lucene-java-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Jain Rahul <ja...@ivycomptech.com>
Subject flush/commit seems to be taking a huge time after some time.
Date Thu, 18 Oct 2012 18:34:16 GMT
Hi All,

I am currently using the solr-4.0.0 to allow searching the logs for one of our project. I
am testing with a dataset of around 17Gb containing only logs. We prepare each line as one
document (SolrInputDocument) having 9 fields, around having size as 200byte to 500 bytes(If
exception stack trace). Roughly each 1 Gb contains around 5million log lines, so the same
number of document object are prepared. We are using solr as embedded mode (EmbeddedSolrServer).

While indexing initially solr/lucene is able to process around 8Gb in 8-10 minutes but slowly
it is getting slowed(see below logs). By looking at IO it seems that io wait time roughly
stands at 50-60% and at that time all threads running for indexing get in pause state. We
have observed the pause time around 47 mins with cpu being 100 to 200% max (total is 2400%
as 24 core) at that time.

We have disable the merging in this by creating an extension of NoMergeScheduler (Just for
testing). By looking at thread dumps it seems to be  that all threads are waiting on writeBytes
method of RandomAccessFile.

Can you guys please suggest what might be going wrong.  Please let me know if I need to provide
more details.

Couldn't attach the logs (thread-dumps, iostat and infostream file) due to size so uploaded
at below link.

http://dc414.2shared.com/download/s0_EKGIi/logs.zip?tsid=20121018-181700-bce0d673
or
http://www.2shared.com/file/s0_EKGIi/logs.html

Some insights about the app.

Below is the machine configuration.
Physical server, Intel 2.4 Ghz 12 core(each is dual core), 48 GB RAM. Disk is local
Java Process is with 12gb heap.
6 Solr core,  Having a global thread pool of 32 threads, where for one core max 8 threads
can work at a time (achieved by using semaphore), the whole application is based on Producer
-Consumer design. Producer reads the file, create a 10k document and add it to ThreadPoolExecutor
as a task.
We have made some small extension to lucene/solr api (by extending classes) to achieve reusing
lucene document object and by-passing the xml marshalling/unmarshalling and directly passing
SolrInputDocument object to solr's UpdateProcessor.

Snippet of Log that shows the time difference:

2012-10-17 12:04:56,873 INFO  [LOGMINER -1-thread-2] NEW_INDEXER_LOGGER: Total time taken
to index gclog_10.1.86.212 is 20711
2012-10-17 12:04:56,873 INFO  [LOGMINER -1-thread-2] NEW_INDEXER_LOGGER: Total no.of documents
created for gclog_10.1.86.212 is 313431--total:97280056 total processed data size(MB):15546
2012-10-17 12:04:56,873 INFO  [LOGMINER -1-thread-2] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:04:58,397 INFO  [LOGMINER -1-thread-8] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:04:58,397 INFO  [LOGMINER -1-thread-8] NEW_INDEXER_LOGGER: Total time taken
to index gclog_10.1.65.231 is 39967
2012-10-17 12:04:58,397 INFO  [LOGMINER -1-thread-8] NEW_INDEXER_LOGGER: Total no.of documents
created for gclog_10.1.65.231 is 314402--total:97340056 total processed data size(MB):15568
2012-10-17 12:04:58,397 INFO  [LOGMINER -1-thread-8] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:51:16,590 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:51:16,590 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: Total time taken
to index gsctlog_10.1.86.207 is 2830070
2012-10-17 12:51:16,590 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: Total no.of documents
created for gsctlog_10.1.86.207 is 146808--total:98330056 total processed data size(MB):15591
2012-10-17 12:51:16,590 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:51:21,877 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: #############################
2012-10-17 12:51:21,877 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: Total time taken
to index gslog_10.1.86.207 is 5287
2012-10-17 12:51:21,877 INFO  [LOGMINER -1-thread-9] NEW_INDEXER_LOGGER: Total no.of documents
created for gslog_10.1.86.207 is 59800--total:98650056 total processed data size(MB):15612


Solr-Config file.

   <directoryFactory name="DirectoryFactory" class="${solr.directoryFactory:solr.StandardDirectoryFactory}"/>

<indexConfig>
    <ramBufferSizeMB>1024</ramBufferSizeMB>
  <infoStream file="/home/ppoker/apache-solr-4.0.0/example/multicore/INFOSTREAM.txt">true</infoStream>
  </indexConfig>

<updateHandler class="solr.DirectUpdateHandler2">
     <autoCommit>
       <maxTime>1800000</maxTime> // 30 mins,
       <openSearcher>false</openSearcher>
     </autoCommit>
  </updateHandler>


Regards
Rahul
This email and any attachments are confidential, and may be legally privileged and protected
by copyright. If you are not the intended recipient dissemination or copying of this email
is prohibited. If you have received this in error, please notify the sender by replying by
email and then delete the email completely from your system. Any views or opinions are solely
those of the sender. This communication is not intended to form a binding contract unless
expressly indicated to the contrary and properly authorised. Any actions taken on the basis
of this email are at the recipient's own risk.

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message