You are viewing a plain text version of this content. The canonical link for it is here.
Posted to java-user@lucene.apache.org by alfredhong <ah...@proofpoint.com> on 2011/10/26 19:05:00 UTC

IndexWriter loops trying to merge using ConcurrentMergeScheduler

This is with lucene 3.0.3 running JDK 6u20 64-bit.  

I'm running into an issue where merges are looping seemingly randomly with
the use of ConcurrentMergeSchduler.  By "seemingly randomly", I mean that
with repeated process restarts against very much the same data set this
behavior will occur, but it doesn't seem to be triggered by a specific
document, i.e. this is not caused by specific data.

The following is the DEBUG logging on IndexMerger.  Has anyone seen this
before or know what the issue is and the resolution for this?  Note that
using "merge: total" as a milestone marker, you'll see that the Merge Thread
#0 is looping repeatedly.


2011-10-25T23:27:36.791+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: setInfoStream:
dir=org.apache.lucene.store.NIOFSDirectory@/home/merger/25331545000616551-12
lockFactory=org.apache.lucene.store.NativeFSLockFactory@142c29ff
mergePolicy=org.apache.lucene.index.BalancedSegmentMergePolicy@5421b305
mergeScheduler=org.apache.lucene.index.ConcurrentMergeScheduler@70703869
ramBufferSizeMB=100.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1
maxFieldLength=2147483647 index=
2011-10-25T23:27:36.795+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: flush at addIndexesNoOptimize
2011-10-25T23:27:36.795+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: flush: now pause all indexing threads
2011-10-25T23:27:36.796+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]:   flush: segment=null docStoreSegment=null
docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false
numDocs=0 numBufDelTerms=0
2011-10-25T23:27:36.796+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]:   index before flush 
2011-10-25T23:27:36.796+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: now start transaction
2011-10-25T23:27:36.803+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx30877->_0 _0:Cx12519->_0
[total 1 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx28305->_0 _0:Cx19527->_0
[total 2 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx4605->_0 _0:Cx37050->_0
[total 3 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx30862->_0 _0:Cx16948->_0
[total 4 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx22130->_0 _0:Cx47560->_0
[total 5 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: add merge to pendingMerges: _0:Cx11198->_0 _0:Cx53059->_0
[total 6 pending]
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: CMS: now merge
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: CMS:   index: _0:Cx11198->_0** _0:Cx53059->_0**
_0:Cx22130->_0** _0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0**
_0:Cx30401->_0** _0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0**
_0:Cx37050->_0** _0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0**
_0:Cx30877->_0** _0:Cx12519->_0**
2011-10-25T23:27:36.804+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: CMS:   consider merge _0:Cx30877->_0 _0:Cx12519->_0 into
_0 [mergeDocStores]
2011-10-25T23:27:36.805+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: CMS:     launch new thread [Lucene Merge Thread #0]
2011-10-25T23:27:36.805+0000	DEBUG	pool-9-thread-1
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
pool-9-thread-1]: CMS:     too many merge threads running; stalling...
2011-10-25T23:27:36.805+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: start
2011-10-25T23:27:36.806+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:36.806+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
Lucene Merge Thread #0]: merging _0:Cx30877->_0 _0:Cx12519->_0 into _0
[mergeDocStores]
2011-10-25T23:27:36.807+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:36 UTC 2011;
Lucene Merge Thread #0]: merge: *total 43396 docs*
2011-10-25T23:27:37.476+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:Cx30877->_0 _0:Cx12519->_0 into _0
[mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
_0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
_0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0** _0:Cx37050->_0**
_0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:Cx30877->_0**
_0:Cx12519->_0**
2011-10-25T23:27:37.476+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:Cx30877->_0 _0:Cx12519->_0
into _0 [mergeDocStores]
2011-10-25T23:27:37.476+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [15 segments ; isCommit
= false]
2011-10-25T23:27:37.477+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _0:Cx4605->_0
_0:Cx37050->_0 into _2 [mergeDocStores]
2011-10-25T23:27:37.477+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:37.477+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: merging _0:Cx4605->_0 _0:Cx37050->_0 into _2
[mergeDocStores]
2011-10-25T23:27:37.478+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:37 UTC 2011;
Lucene Merge Thread #0]: *merge: total 41655 docs*
2011-10-25T23:27:38.071+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:Cx4605->_0 _0:Cx37050->_0 into _2
[mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
_0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
_0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0** _0:Cx37050->_0**
_0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
2011-10-25T23:27:38.072+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:Cx4605->_0 _0:Cx37050->_0
into _2 [mergeDocStores]
2011-10-25T23:27:38.072+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [14 segments ; isCommit
= false]
2011-10-25T23:27:38.072+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge
_0:Cx30862->_0 _0:Cx16948->_0 into _3 [mergeDocStores]
2011-10-25T23:27:38.073+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:38.073+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: merging _0:Cx30862->_0 _0:Cx16948->_0 into _3
[mergeDocStores]
2011-10-25T23:27:38.073+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: *merge: total 47810 docs*
2011-10-25T23:27:38.709+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:Cx30862->_0 _0:Cx16948->_0 into _3
[mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
_0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
_0:Cx36858->_0** _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0**
_0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
2011-10-25T23:27:38.709+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:Cx30862->_0 _0:Cx16948->_0
into _3 [mergeDocStores]
2011-10-25T23:27:38.709+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [13 segments ; isCommit
= false]
2011-10-25T23:27:38.710+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge
_0:Cx22130->_0 _0:Cx47560->_0 into _4 [mergeDocStores]
2011-10-25T23:27:38.710+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:38.710+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: merging _0:Cx22130->_0 _0:Cx47560->_0 into _4
[mergeDocStores]
2011-10-25T23:27:38.711+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:38 UTC 2011;
Lucene Merge Thread #0]: *merge: total 69690 docs*
2011-10-25T23:27:39.750+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:Cx22130->_0 _0:Cx47560->_0 into _4
[mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
_0:Cx47560->_0** _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
_0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
_2:Cx75008->_0** _0:C43396
2011-10-25T23:27:39.750+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:Cx22130->_0 _0:Cx47560->_0
into _4 [mergeDocStores]
2011-10-25T23:27:39.750+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [12 segments ; isCommit
= false]
2011-10-25T23:27:39.751+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge
_0:Cx11198->_0 _0:Cx53059->_0 into _5 [mergeDocStores]
2011-10-25T23:27:39.751+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:39.751+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: merging _0:Cx11198->_0 _0:Cx53059->_0 into _5
[mergeDocStores]
2011-10-25T23:27:39.752+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:39 UTC 2011;
Lucene Merge Thread #0]: *merge: total 64257 docs*
2011-10-25T23:27:40.770+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:Cx11198->_0 _0:Cx53059->_0 into _5
[mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _4:C69690 _3:C47810
_0:Cx30401->_0** _0:Cx36858->_0** _0:Cx37828->_0** _2:C41655
_0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:Cx11198->_0 _0:Cx53059->_0
into _5 [mergeDocStores]
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
= false]
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _0:C43396 [total 1
pending]
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _0:C43396
into _6 [mergeDocStores]
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:40.771+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: merging _0:C43396 into _6 [mergeDocStores]
2011-10-25T23:27:40.772+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:40 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*
2011-10-25T23:27:41.384+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _0:C43396 into _6 [mergeDocStores]
index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
_0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
_2:Cx75008->_0** _0:C43396
2011-10-25T23:27:41.384+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _0:C43396 into _6
[mergeDocStores]
2011-10-25T23:27:41.384+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
= false]
2011-10-25T23:27:41.384+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.tis"
2011-10-25T23:27:41.386+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.prx"
2011-10-25T23:27:41.387+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.nrm"
2011-10-25T23:27:41.387+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.fnm"
2011-10-25T23:27:41.387+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.tii"
2011-10-25T23:27:41.387+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.frq"
2011-10-25T23:27:41.389+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.fdx"
2011-10-25T23:27:41.389+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: delete "_0.fdt"
2011-10-25T23:27:41.394+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _6:C43396 [total 1
pending]
2011-10-25T23:27:41.395+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _6:C43396
into _7 [mergeDocStores]
2011-10-25T23:27:41.395+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:41.395+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: merging _6:C43396 into _7 [mergeDocStores]
2011-10-25T23:27:41.395+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:41 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*
2011-10-25T23:27:42.012+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _6:C43396 into _7 [mergeDocStores]
index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
_0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
_2:Cx75008->_0** _6:C43396
2011-10-25T23:27:42.030+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _6:C43396 into _7
[mergeDocStores]
2011-10-25T23:27:42.030+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
= false]
2011-10-25T23:27:42.030+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.frq"
2011-10-25T23:27:42.032+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.fdx"
2011-10-25T23:27:42.032+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.tis"
2011-10-25T23:27:42.035+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.tii"
2011-10-25T23:27:42.035+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.prx"
2011-10-25T23:27:42.036+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.fnm"
2011-10-25T23:27:42.036+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.fdt"
2011-10-25T23:27:42.043+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: delete "_6.nrm"
2011-10-25T23:27:42.043+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _7:C43396 [total 1
pending]
2011-10-25T23:27:42.043+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _7:C43396
into _8 [mergeDocStores]
2011-10-25T23:27:42.043+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:42.044+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: merging _7:C43396 into _8 [mergeDocStores]
2011-10-25T23:27:42.044+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:42 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*
2011-10-25T23:27:43.958+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _7:C43396 into _8 [mergeDocStores]
index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
_0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
_2:Cx75008->_0** _7:C43396
2011-10-25T23:27:43.958+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _7:C43396 into _8
[mergeDocStores]
2011-10-25T23:27:43.959+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
= false]
2011-10-25T23:27:43.959+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.fnm"
2011-10-25T23:27:43.959+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.tis"
2011-10-25T23:27:43.963+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.nrm"
2011-10-25T23:27:43.963+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.frq"
2011-10-25T23:27:43.965+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.tii"
2011-10-25T23:27:43.965+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.fdx"
2011-10-25T23:27:43.965+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.fdt"
2011-10-25T23:27:43.975+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: delete "_7.prx"
2011-10-25T23:27:43.976+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _8:C43396 [total 1
pending]
2011-10-25T23:27:43.977+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _8:C43396
into _9 [mergeDocStores]
2011-10-25T23:27:43.977+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:27:43.977+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: merging _8:C43396 into _9 [mergeDocStores]
2011-10-25T23:27:43.977+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:27:43 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*
2011-10-25T23:59:53.355+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: commitMerge: _24m:C43396 into _24n [mergeDocStores]
index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
_0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
_2:Cx75008->_0** _24m:C43396
2011-10-25T23:59:53.355+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: commitMergeDeletes _24m:C43396 into _24n
[mergeDocStores]
2011-10-25T23:59:53.355+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
= false]
2011-10-25T23:59:53.355+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.tis"
2011-10-25T23:59:53.358+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.nrm"
2011-10-25T23:59:53.358+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.tii"
2011-10-25T23:59:53.358+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.fdt"
2011-10-25T23:59:53.367+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.fnm"
2011-10-25T23:59:53.367+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.frq"
2011-10-25T23:59:53.369+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.fdx"
2011-10-25T23:59:53.369+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: delete "_24m.prx"
2011-10-25T23:59:53.370+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _24n:C43396 [total 1
pending]
2011-10-25T23:59:53.370+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _24n:C43396
into _24o [mergeDocStores]
2011-10-25T23:59:53.370+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:59:53.370+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: merging _24n:C43396 into _24o [mergeDocStores]
2011-10-25T23:59:53.371+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:53 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*
2011-10-25T23:59:59.071+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.tis"
2011-10-25T23:59:59.074+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.prx"
2011-10-25T23:59:59.075+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.fdt"
2011-10-25T23:59:59.083+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.fnm"
2011-10-25T23:59:59.083+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.frq"
2011-10-25T23:59:59.085+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.fdx"
2011-10-25T23:59:59.085+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.tii"
2011-10-25T23:59:59.085+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IFD [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: delete "_24u.nrm"
2011-10-25T23:59:59.086+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: add merge to pendingMerges: _24v:C43396 [total 1
pending]
2011-10-25T23:59:59.086+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: CMS:   merge thread: do another merge _24v:C43396
into _24w [mergeDocStores]
2011-10-25T23:59:59.086+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: now merge
2011-10-25T23:59:59.086+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: merging _24v:C43396 into _24w [mergeDocStores]
2011-10-25T23:59:59.086+0000	DEBUG	Lucene Merge Thread #0
org.apache.lucene.index.IndexWriter	IW 15 [Tue Oct 25 23:59:59 UTC 2011;
Lucene Merge Thread #0]: *merge: total 43396 docs*


--
View this message in context: http://lucene.472066.n3.nabble.com/IndexWriter-loops-trying-to-merge-using-ConcurrentMergeScheduler-tp3455163p3455163.html
Sent from the Lucene - Java Users mailing list archive at Nabble.com.

---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org


Re: IndexWriter loops trying to merge using ConcurrentMergeScheduler

Posted by Michael McCandless <lu...@mikemccandless.com>.
Are you sure SerialMergeScheduler with BalancedMP doesn't loop
infinitely (but CMS does)?

How many threads are you using for indexing?

Mike McCandless

http://blog.mikemccandless.com

On Thu, Oct 27, 2011 at 8:22 PM, alfredhong <ah...@proofpoint.com> wrote:
> Hi, Mike,
>
> Thanks for your analysis.  You are correct in that
> BalancedSegmentMergePolicy is used.  We previously used
> LogByteSizeMergePolicy but might have run into some other issues that I was
> involved in so weren't using it.
>
> Re: TieredMergePolicy, we'll definitely check that out when we update to the
> latest and greatest, which is a much bigger effort than we can afford right
> now.  Your blog is a great writeup, btw.
>
> To get around the issue we have now, we have the option of using
> SerialMergeScheduler instead and that has been working great for us in the
> mean time.
>
> Alfred
>
>
>
> --
> View this message in context: http://lucene.472066.n3.nabble.com/IndexWriter-loops-trying-to-merge-using-ConcurrentMergeScheduler-tp3455163p3459658.html
> Sent from the Lucene - Java Users mailing list archive at Nabble.com.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
> For additional commands, e-mail: java-user-help@lucene.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org


Re: IndexWriter loops trying to merge using ConcurrentMergeScheduler

Posted by alfredhong <ah...@proofpoint.com>.
Hi, Mike,

Thanks for your analysis.  You are correct in that
BalancedSegmentMergePolicy is used.  We previously used
LogByteSizeMergePolicy but might have run into some other issues that I was
involved in so weren't using it.  

Re: TieredMergePolicy, we'll definitely check that out when we update to the
latest and greatest, which is a much bigger effort than we can afford right
now.  Your blog is a great writeup, btw.

To get around the issue we have now, we have the option of using
SerialMergeScheduler instead and that has been working great for us in the
mean time.

Alfred



--
View this message in context: http://lucene.472066.n3.nabble.com/IndexWriter-loops-trying-to-merge-using-ConcurrentMergeScheduler-tp3455163p3459658.html
Sent from the Lucene - Java Users mailing list archive at Nabble.com.

---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org


Re: IndexWriter loops trying to merge using ConcurrentMergeScheduler

Posted by Michael McCandless <lu...@mikemccandless.com>.
It looks like you are using BalancedSegmentMergePolicy right?  And
somehow it gets stuck in a state where it keeps merging the same
single segment into a new segment, which is odd.  Likely this is a bug
in BSMP.

Do you see this same looping with eg LogByteSizeMergePolicy?

Note that newer versions of Lucene have a new MP, TieredMergePolicy,
which generally does a better job picking merges since it's able to
merge out-of-order segments... see this post for more details:

    http://blog.mikemccandless.com/2011/02/visualizing-lucenes-segment-merges.html

Mike McCandless

http://blog.mikemccandless.com

On Wed, Oct 26, 2011 at 1:05 PM, alfredhong <ah...@proofpoint.com> wrote:
> This is with lucene 3.0.3 running JDK 6u20 64-bit.
>
> I'm running into an issue where merges are looping seemingly randomly with
> the use of ConcurrentMergeSchduler.  By "seemingly randomly", I mean that
> with repeated process restarts against very much the same data set this
> behavior will occur, but it doesn't seem to be triggered by a specific
> document, i.e. this is not caused by specific data.
>
> The following is the DEBUG logging on IndexMerger.  Has anyone seen this
> before or know what the issue is and the resolution for this?  Note that
> using "merge: total" as a milestone marker, you'll see that the Merge Thread
> #0 is looping repeatedly.
>
>
> 2011-10-25T23:27:36.791+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: setInfoStream:
> dir=org.apache.lucene.store.NIOFSDirectory@/home/merger/25331545000616551-12
> lockFactory=org.apache.lucene.store.NativeFSLockFactory@142c29ff
> mergePolicy=org.apache.lucene.index.BalancedSegmentMergePolicy@5421b305
> mergeScheduler=org.apache.lucene.index.ConcurrentMergeScheduler@70703869
> ramBufferSizeMB=100.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1
> maxFieldLength=2147483647 index=
> 2011-10-25T23:27:36.795+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: flush at addIndexesNoOptimize
> 2011-10-25T23:27:36.795+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: flush: now pause all indexing threads
> 2011-10-25T23:27:36.796+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]:   flush: segment=null docStoreSegment=null
> docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false
> numDocs=0 numBufDelTerms=0
> 2011-10-25T23:27:36.796+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]:   index before flush
> 2011-10-25T23:27:36.796+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: now start transaction
> 2011-10-25T23:27:36.803+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx30877->_0 _0:Cx12519->_0
> [total 1 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx28305->_0 _0:Cx19527->_0
> [total 2 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx4605->_0 _0:Cx37050->_0
> [total 3 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx30862->_0 _0:Cx16948->_0
> [total 4 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx22130->_0 _0:Cx47560->_0
> [total 5 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: add merge to pendingMerges: _0:Cx11198->_0 _0:Cx53059->_0
> [total 6 pending]
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: CMS: now merge
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: CMS:   index: _0:Cx11198->_0** _0:Cx53059->_0**
> _0:Cx22130->_0** _0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0**
> _0:Cx30401->_0** _0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0**
> _0:Cx37050->_0** _0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0**
> _0:Cx30877->_0** _0:Cx12519->_0**
> 2011-10-25T23:27:36.804+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: CMS:   consider merge _0:Cx30877->_0 _0:Cx12519->_0 into
> _0 [mergeDocStores]
> 2011-10-25T23:27:36.805+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: CMS:     launch new thread [Lucene Merge Thread #0]
> 2011-10-25T23:27:36.805+0000    DEBUG   pool-9-thread-1
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> pool-9-thread-1]: CMS:     too many merge threads running; stalling...
> 2011-10-25T23:27:36.805+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: start
> 2011-10-25T23:27:36.806+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:36.806+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> Lucene Merge Thread #0]: merging _0:Cx30877->_0 _0:Cx12519->_0 into _0
> [mergeDocStores]
> 2011-10-25T23:27:36.807+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:36 UTC 2011;
> Lucene Merge Thread #0]: merge: *total 43396 docs*
> 2011-10-25T23:27:37.476+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:Cx30877->_0 _0:Cx12519->_0 into _0
> [mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
> _0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
> _0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0** _0:Cx37050->_0**
> _0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:Cx30877->_0**
> _0:Cx12519->_0**
> 2011-10-25T23:27:37.476+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:Cx30877->_0 _0:Cx12519->_0
> into _0 [mergeDocStores]
> 2011-10-25T23:27:37.476+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [15 segments ; isCommit
> = false]
> 2011-10-25T23:27:37.477+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _0:Cx4605->_0
> _0:Cx37050->_0 into _2 [mergeDocStores]
> 2011-10-25T23:27:37.477+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:37.477+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: merging _0:Cx4605->_0 _0:Cx37050->_0 into _2
> [mergeDocStores]
> 2011-10-25T23:27:37.478+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:37 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 41655 docs*
> 2011-10-25T23:27:38.071+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:Cx4605->_0 _0:Cx37050->_0 into _2
> [mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
> _0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
> _0:Cx36858->_0** _0:Cx37828->_0** _0:Cx4605->_0** _0:Cx37050->_0**
> _0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
> 2011-10-25T23:27:38.072+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:Cx4605->_0 _0:Cx37050->_0
> into _2 [mergeDocStores]
> 2011-10-25T23:27:38.072+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [14 segments ; isCommit
> = false]
> 2011-10-25T23:27:38.072+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge
> _0:Cx30862->_0 _0:Cx16948->_0 into _3 [mergeDocStores]
> 2011-10-25T23:27:38.073+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:38.073+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: merging _0:Cx30862->_0 _0:Cx16948->_0 into _3
> [mergeDocStores]
> 2011-10-25T23:27:38.073+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 47810 docs*
> 2011-10-25T23:27:38.709+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:Cx30862->_0 _0:Cx16948->_0 into _3
> [mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
> _0:Cx47560->_0** _0:Cx30862->_0** _0:Cx16948->_0** _0:Cx30401->_0**
> _0:Cx36858->_0** _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0**
> _0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
> 2011-10-25T23:27:38.709+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:Cx30862->_0 _0:Cx16948->_0
> into _3 [mergeDocStores]
> 2011-10-25T23:27:38.709+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [13 segments ; isCommit
> = false]
> 2011-10-25T23:27:38.710+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge
> _0:Cx22130->_0 _0:Cx47560->_0 into _4 [mergeDocStores]
> 2011-10-25T23:27:38.710+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:38.710+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: merging _0:Cx22130->_0 _0:Cx47560->_0 into _4
> [mergeDocStores]
> 2011-10-25T23:27:38.711+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:38 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 69690 docs*
> 2011-10-25T23:27:39.750+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:Cx22130->_0 _0:Cx47560->_0 into _4
> [mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _0:Cx22130->_0**
> _0:Cx47560->_0** _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
> _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
> _2:Cx75008->_0** _0:C43396
> 2011-10-25T23:27:39.750+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:Cx22130->_0 _0:Cx47560->_0
> into _4 [mergeDocStores]
> 2011-10-25T23:27:39.750+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [12 segments ; isCommit
> = false]
> 2011-10-25T23:27:39.751+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge
> _0:Cx11198->_0 _0:Cx53059->_0 into _5 [mergeDocStores]
> 2011-10-25T23:27:39.751+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:39.751+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: merging _0:Cx11198->_0 _0:Cx53059->_0 into _5
> [mergeDocStores]
> 2011-10-25T23:27:39.752+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:39 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 64257 docs*
> 2011-10-25T23:27:40.770+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:Cx11198->_0 _0:Cx53059->_0 into _5
> [mergeDocStores] index=_0:Cx11198->_0** _0:Cx53059->_0** _4:C69690 _3:C47810
> _0:Cx30401->_0** _0:Cx36858->_0** _0:Cx37828->_0** _2:C41655
> _0:Cx28305->_0** _0:Cx19527->_0** _2:Cx75008->_0** _0:C43396
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:Cx11198->_0 _0:Cx53059->_0
> into _5 [mergeDocStores]
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
> = false]
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _0:C43396 [total 1
> pending]
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _0:C43396
> into _6 [mergeDocStores]
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:40.771+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: merging _0:C43396 into _6 [mergeDocStores]
> 2011-10-25T23:27:40.772+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:40 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
> 2011-10-25T23:27:41.384+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _0:C43396 into _6 [mergeDocStores]
> index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
> _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
> _2:Cx75008->_0** _0:C43396
> 2011-10-25T23:27:41.384+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _0:C43396 into _6
> [mergeDocStores]
> 2011-10-25T23:27:41.384+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
> = false]
> 2011-10-25T23:27:41.384+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.tis"
> 2011-10-25T23:27:41.386+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.prx"
> 2011-10-25T23:27:41.387+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.nrm"
> 2011-10-25T23:27:41.387+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.fnm"
> 2011-10-25T23:27:41.387+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.tii"
> 2011-10-25T23:27:41.387+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.frq"
> 2011-10-25T23:27:41.389+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.fdx"
> 2011-10-25T23:27:41.389+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: delete "_0.fdt"
> 2011-10-25T23:27:41.394+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _6:C43396 [total 1
> pending]
> 2011-10-25T23:27:41.395+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _6:C43396
> into _7 [mergeDocStores]
> 2011-10-25T23:27:41.395+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:41.395+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: merging _6:C43396 into _7 [mergeDocStores]
> 2011-10-25T23:27:41.395+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:41 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
> 2011-10-25T23:27:42.012+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _6:C43396 into _7 [mergeDocStores]
> index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
> _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
> _2:Cx75008->_0** _6:C43396
> 2011-10-25T23:27:42.030+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _6:C43396 into _7
> [mergeDocStores]
> 2011-10-25T23:27:42.030+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
> = false]
> 2011-10-25T23:27:42.030+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.frq"
> 2011-10-25T23:27:42.032+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.fdx"
> 2011-10-25T23:27:42.032+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.tis"
> 2011-10-25T23:27:42.035+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.tii"
> 2011-10-25T23:27:42.035+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.prx"
> 2011-10-25T23:27:42.036+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.fnm"
> 2011-10-25T23:27:42.036+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.fdt"
> 2011-10-25T23:27:42.043+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: delete "_6.nrm"
> 2011-10-25T23:27:42.043+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _7:C43396 [total 1
> pending]
> 2011-10-25T23:27:42.043+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _7:C43396
> into _8 [mergeDocStores]
> 2011-10-25T23:27:42.043+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:42.044+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: merging _7:C43396 into _8 [mergeDocStores]
> 2011-10-25T23:27:42.044+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:42 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
> 2011-10-25T23:27:43.958+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _7:C43396 into _8 [mergeDocStores]
> index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
> _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
> _2:Cx75008->_0** _7:C43396
> 2011-10-25T23:27:43.958+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _7:C43396 into _8
> [mergeDocStores]
> 2011-10-25T23:27:43.959+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
> = false]
> 2011-10-25T23:27:43.959+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.fnm"
> 2011-10-25T23:27:43.959+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.tis"
> 2011-10-25T23:27:43.963+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.nrm"
> 2011-10-25T23:27:43.963+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.frq"
> 2011-10-25T23:27:43.965+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.tii"
> 2011-10-25T23:27:43.965+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.fdx"
> 2011-10-25T23:27:43.965+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.fdt"
> 2011-10-25T23:27:43.975+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: delete "_7.prx"
> 2011-10-25T23:27:43.976+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _8:C43396 [total 1
> pending]
> 2011-10-25T23:27:43.977+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _8:C43396
> into _9 [mergeDocStores]
> 2011-10-25T23:27:43.977+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:27:43.977+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: merging _8:C43396 into _9 [mergeDocStores]
> 2011-10-25T23:27:43.977+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:27:43 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
> 2011-10-25T23:59:53.355+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: commitMerge: _24m:C43396 into _24n [mergeDocStores]
> index=_5:C64257 _4:C69690 _3:C47810 _0:Cx30401->_0** _0:Cx36858->_0**
> _0:Cx37828->_0** _2:C41655 _0:Cx28305->_0** _0:Cx19527->_0**
> _2:Cx75008->_0** _24m:C43396
> 2011-10-25T23:59:53.355+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: commitMergeDeletes _24m:C43396 into _24n
> [mergeDocStores]
> 2011-10-25T23:59:53.355+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: now checkpoint "segments_1" [11 segments ; isCommit
> = false]
> 2011-10-25T23:59:53.355+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.tis"
> 2011-10-25T23:59:53.358+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.nrm"
> 2011-10-25T23:59:53.358+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.tii"
> 2011-10-25T23:59:53.358+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.fdt"
> 2011-10-25T23:59:53.367+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.fnm"
> 2011-10-25T23:59:53.367+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.frq"
> 2011-10-25T23:59:53.369+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.fdx"
> 2011-10-25T23:59:53.369+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: delete "_24m.prx"
> 2011-10-25T23:59:53.370+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _24n:C43396 [total 1
> pending]
> 2011-10-25T23:59:53.370+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _24n:C43396
> into _24o [mergeDocStores]
> 2011-10-25T23:59:53.370+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:59:53.370+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: merging _24n:C43396 into _24o [mergeDocStores]
> 2011-10-25T23:59:53.371+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:53 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
> 2011-10-25T23:59:59.071+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.tis"
> 2011-10-25T23:59:59.074+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.prx"
> 2011-10-25T23:59:59.075+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.fdt"
> 2011-10-25T23:59:59.083+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.fnm"
> 2011-10-25T23:59:59.083+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.frq"
> 2011-10-25T23:59:59.085+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.fdx"
> 2011-10-25T23:59:59.085+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.tii"
> 2011-10-25T23:59:59.085+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IFD [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: delete "_24u.nrm"
> 2011-10-25T23:59:59.086+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: add merge to pendingMerges: _24v:C43396 [total 1
> pending]
> 2011-10-25T23:59:59.086+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: CMS:   merge thread: do another merge _24v:C43396
> into _24w [mergeDocStores]
> 2011-10-25T23:59:59.086+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: now merge
> 2011-10-25T23:59:59.086+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: merging _24v:C43396 into _24w [mergeDocStores]
> 2011-10-25T23:59:59.086+0000    DEBUG   Lucene Merge Thread #0
> org.apache.lucene.index.IndexWriter     IW 15 [Tue Oct 25 23:59:59 UTC 2011;
> Lucene Merge Thread #0]: *merge: total 43396 docs*
>
>
> --
> View this message in context: http://lucene.472066.n3.nabble.com/IndexWriter-loops-trying-to-merge-using-ConcurrentMergeScheduler-tp3455163p3455163.html
> Sent from the Lucene - Java Users mailing list archive at Nabble.com.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
> For additional commands, e-mail: java-user-help@lucene.apache.org
>
>

---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org