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 ni...@emc.com on 2011/11/14 22:36:35 UTC
Index Corruption with Lucene 2.9.3
We are seeing Index corruption very often with version 2.9.3. Our indexing process is on Linux ( centos 5 ). Index is created on a mounted drive which is a shared drive from Windows 2008 server running in a VM. We generally see index corruption in merge or optimize after indexing runs continuously for 6-7 hrs with index size reaching around 7-8GB. To reproduce the corruptions sooner, I have placed the merge ( maybemerge ) call immediately after addIndex is called. We have a final index which is in the mounted drive, we always add documents to an local intermediate index and then call add index and merge to the final index.
The exception that I get -
2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard 0, guid 10.10.176.148-1321045422606-204: Error in addIndex()/kazMaybeMerge(): /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException: background merge hit exception: _1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerIndex(MergerContext.java:1004)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerIndex(MergerContext.java:1094)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFiler(MergerContext.java:1140)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompressModifier.java:375)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompressModifier.java:181)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompressModifier.java:106)
com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
CheckIndex command shows the following output -
NOTE: testing will be more thorough if you run java with '-ea:org.apache.lucene...', so assertions are enabled
Opening index @ .
Segments file=segments_23 numSegments=1 version=FORMAT_DIAGNOSTICS [Lucene 2.9]
1 of 1: name=_1t docCount=262436
compound=true
hasProx=true
numFiles=1
size (MB)=937.835
diagnostics = {optimize=true, mergeFactor=2, os.version=2.6.18-92.1.18.el5, os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev, source=merge, os.arch=i386, java.version=1.6.0_02, java.vendor=Sun Microsystems Inc.}
no deletions
test: open reader.........OK
test: fields..............OK [79 fields]
test: field norms.........OK [79 fields]
test: terms, freq, prox...ERROR [term fulltext:creativecommons: doc 262603 >= maxDoc 262436]
java.lang.RuntimeException: term fulltext:creativecommons: doc 262603 >= maxDoc 262436
at org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
test: stored fields.......OK [524872 total field count; avg 2 fields per doc]
test: term vectors........OK [0 total vector count; avg 0 term/freq vector fields per doc]
FAILED
WARNING: fixIndex() would remove reference to this segment; full exception:
java.lang.RuntimeException: Term Index test failed
at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
WARNING: 1 broken segments (containing 262436 documents) detected
WARNING: would write new segments file, and 262436 documents would be lost, if -fix were specified
Lucene Indexwriter infostream around the corrupt segment _1t shows -
9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: setInfoStream: dir=org.apache.lucene.store.S impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary autoCommit=true mergePolicy=org. apache.lucene.index.LogByteSizeMergePolicy@2ac02f<ma...@2ac02f> mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: setMaxBufferedDocs 10000
9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush at addIndexes
9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077
9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now start transaction
9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush at startTransaction
9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077
9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-361_0:cx1359**
9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077 _10.10.176. 148-1321053007682-361_0:cx1359**
9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: add merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-361_0:cx1359 [optimize] [total 1 pending]
9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1s:c261077 _10.10.176.148-132 1053007682-361_0:cx1359**
9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: launch new thread [Lucene Merge Thr ead #0]
9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
9642 IW 130 [Lucene Merge Thread #0]: now merge
9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9644 merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<ma...@116eedb>
9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize] [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now commit transaction
9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now checkpoint "segments_1u" [1 segments ; isCo mmit = false]
9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit(): start sizeInBytes=0
9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit index=_1t:c262436 changeCount=4
9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now sync _1t.cfs
9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: done all syncs
9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: pendingCommit != null
9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: wrote segments file "segments_1v"
9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now checkpoint "segments_1v" [1 segments ; isCo mmit = true]
9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: deleteCommits: now decRef commit "segments_1u"
9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete "_1s.cfs"
9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete "segments_1u"
9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: done
9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: LMP: findMerges: 1 segments
9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: LMP: level 8.242726 to 8.992726: 1 segment s
9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1t:c262436
9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now flush at close
9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1t:c262436
9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1t:c262436
9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now call final commit()
9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit(): start sizeInBytes=0
9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: skip startCommit(): no changes pending
9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: pendingCommit == null; skip
9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: done
9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at close: _1t:c262436
9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: setInfoStream deletionPolicy=org.apache.lucene. index.KeepOnlyLastCommitDeletionPolicy@28cdb8<ma...@28cdb8>
9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: setInfoStream: dir=org.apache.lucene.store.S impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/secondary autoCommit=true mergePolicy=or g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<ma...@da05c8> mergeScheduler=org.apache.lucene.index.ConcurrentMerge Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: setMaxBufferedDocs 10000
9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush at addIndexes
9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077
9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now start transaction
9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush at startTransaction
9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077
9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-361_0:cx1359**
9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1s:c261077 _10.10.176. 148-1321053007682-361_0:cx1359**
9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: add merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-361_0:cx1359 [optimize] [total 1 pending]
9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1s:c261077 _10.10.176.148-132 1053007682-361_0:cx1359**
9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: launch new thread [Lucene Merge Thr ead #0]
9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
9716 IW 131 [Lucene Merge Thread #0]: now merge
9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9718 merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<ma...@15aa40f>
9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize] [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize] [mergeDocStores]
9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1 segments ; isCommit = false]
9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now commit transaction
9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now checkpoint "segments_1u" [1 segments ; isCo mmit = false]
9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit(): start sizeInBytes=0
9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit index=_1t:c262436 changeCount=4
9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now sync _1t.cfs
9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: done all syncs
9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: pendingCommit != null
9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: wrote segments file "segments_1v"
9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now checkpoint "segments_1v" [1 segments ; isCo mmit = true]
9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: deleteCommits: now decRef commit "segments_1u"
9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete "_1s.cfs"
9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete "segments_1u"
9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: done
9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: LMP: findMerges: 1 segments
9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: LMP: level 7.2867203 to 8.03672: 1 segment s
9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1t:c262436
9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now flush at close
9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: now pause all indexing threads
9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: index before flush _1t:c262436
9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: now merge
9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: index: _1t:c262436
9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: CMS: no more merges pending; now return
9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now call final commit()
9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: startCommit(): start sizeInBytes=0
9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: skip startCommit(): no changes pending
9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: pendingCommit == null; skip
9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: commit: done
9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at close: _1t:c262436
9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setInfoStream deletionPolicy=org.apache.lucene. index.KeepOnlyLastCommitDeletionPolicy@8506f9<ma...@8506f9>
9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setInfoStream: dir=org.apache.lucene.store.S impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary autoCommit=true mergePolicy=org. apache.lucene.index.LogByteSizeMergePolicy@18d0653<ma...@18d0653> mergeScheduler=org.apache.lucene.index.ConcurrentMergeS cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setMaxBufferedDocs 10000
9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush at addIndexes
9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: now pause all indexing threads
9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: index before flush _1t:c262436
9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now start transaction
9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush at startTransaction
9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: now pause all indexing threads
9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: index before flush _1t:c262436
9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-204_0:cx4000**
9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: now pause all indexing threads
9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: index before flush _1t:c262436 _10.10.176. 148-1321045422606-204_0:cx4000**
9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: add merge to pendingMerges: _1t:c262436 _10. 10.176.148-1321045422606-204_0:cx4000 [optimize] [total 1 pending]
9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: now merge
9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: index: _1t:c262436 _10.10.176.148-132 1045422606-204_0:cx4000**
9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-204_0:cx4000 into _1u [optimize] [mergeDocStores]
9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: launch new thread [Lucene Merge Thr ead #0]
9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: no more merges pending; now return
9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
9790 IW 132 [Lucene Merge Thread #0]: now merge
9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000 into _1u [optimize] [mergeDocStores]
9792 merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<ma...@3b0c25>
9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
9796 IW 132 [Lucene Merge Thread #0]: handleMergeException: merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into _1u [optimize] [mergeDocStores] exc=org.apache.lucene.index.CorruptIndexException: docs out of order (262439 <= 2096427 )
9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.fdt"
9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.fdx"
9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.fnm"
9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.frq"
9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.prx"
9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.tii"
9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly created unreferenced file "_1u.tis"
9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now rollback transaction
9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: all running merges have aborted
9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now checkpoint "segments_1v" [1 segments ; isCo mmit = false]
9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now flush at close
9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: now pause all indexing threads
9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: index before flush _1t:c262436
9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: now merge
9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: index: _1t:c262436
9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: CMS: no more merges pending; now return
9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now call final commit()
9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: startCommit(): start sizeInBytes=0
9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: startCommit index=_1t:c262436 changeCount=1
9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: done all syncs
9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: commit: pendingCommit != null
9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: commit: wrote segments file "segments_1w"
9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now checkpoint "segments_1w" [1 segments ; isCo mmit = true]
9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: deleteCommits: now decRef commit "segments_1v"
9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: delete "segments_1v"
9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: commit: done
9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: at close: _1t:c262436
9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setInfoStream deletionPolicy=org.apache.lucene. index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<ma...@1ec4b8e>
9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setInfoStream: dir=org.apache.lucene.store.S impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary autoCommit=true mergePolicy=org. apache.lucene.index.LogByteSizeMergePolicy@546a0e<ma...@546a0e> mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1 maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: setMaxBufferedDocs 10000
9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush at addIndexes
9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: now pause all indexing threads
9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: flush: segment=null docStoreSegment=null d ocStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: index before flush _1t:c262436
9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now start transaction
RE: Index Corruption with Lucene 2.9.3
Posted by ni...@emc.com.
Hi Uwe,
I ran my setup with JDK1.6.0_29 .
Exception that I get -
2011-11-15 23:54:24,518 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard 0, guid 10.10.176.148-1321429549689-426: Error in addIndex()/kazMaybeMerge(): /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException: background merge hit exception: _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 into _27 [optimize] [mergeDocStores] % STACK:
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerIndex(MergerContext.java:1004)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerIndex(MergerContext.java:1094)
com.kazeon.search.indexingengine.context.MergerContext.mergeWithFiler(MergerContext.java:1140)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompressModifier.java:375)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompressModifier.java:181)
com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndexOptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompressModifier.java:106)
com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
IndexWriter infostream -
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: index before flush _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500**
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: add merge to pendingMerges: _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 [optimize] [total 1 pending]
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: CMS: now merge
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: CMS: index: _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500**
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: CMS: consider merge _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 into _27 [optimize] [mergeDocStores]
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: CMS: launch new thread [Lucene Merge Thread #0]
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: CMS: no more merges pending; now return
IW 158 [Lucene Merge Thread #0]: CMS: merge thread: start
IW 158 [Lucene Merge Thread #0]: now merge
merge=_26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 into _27 [optimize] [mergeDocStores]
merge=org.apache.lucene.index.MergePolicy$OneMerge@3b784f
index=_26:c330424 _10.10.176.148-1321429549689-426_0:cx4500**
IW 158 [Lucene Merge Thread #0]: merging _26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 into _27 [optimize] [mergeDocStores]
IW 158 [Lucene Merge Thread #0]: merge: total 334924 docs
IW 158 [Lucene Merge Thread #0]: handleMergeException: merge=_26:c330424 _10.10.176.148-1321429549689-426_0:cx4500 into _27 [optimize] [mergeDocStores] exc=org.apache.lucene.index.CorruptIndexException: docs out of order (295226 <= 295226 )
IW 158 [Lucene Merge Thread #0]: hit exception during merge
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.fdt"
IFD [Lucene Merge Thread #0]: delete "_27.fdt"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.fdx"
IFD [Lucene Merge Thread #0]: delete "_27.fdx"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.fnm"
IFD [Lucene Merge Thread #0]: delete "_27.fnm"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.frq"
IFD [Lucene Merge Thread #0]: delete "_27.frq"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.prx"
IFD [Lucene Merge Thread #0]: delete "_27.prx"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.tii"
IFD [Lucene Merge Thread #0]: delete "_27.tii"
IFD [Lucene Merge Thread #0]: refresh [prefix=_27]: removing newly created unreferenced file "_27.tis"
IFD [Lucene Merge Thread #0]: delete "_27.tis"
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: now rollback transaction
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: all running merges have aborted
IFD [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: now checkpoint "segments_28" [1 segments ; isCommit = false]
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: now flush at close
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: flush: now pause all indexing threads
IW 158 [MC:10.10.176.148-1321429549689-426 FS:emag_393219_0]: flush: segment=null docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true flushDocStores=false numDocs=0 numBufDelTerms=0
CheckIndex output -
NOTE: testing will be more thorough if you run java with '-ea:org.apache.lucene...', so assertions are enabled
Opening index @ .
Segments file=segments_aw numSegments=1 version=FORMAT_DIAGNOSTICS [Lucene 2.9]
1 of 1: name=_26 docCount=330424
compound=true
hasProx=true
numFiles=1
size (MB)=1,121.685
diagnostics = {optimize=true, mergeFactor=2, os.version=2.6.18-92.1.18.el5, os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev, source=merge, os.arch=i386, java.version=1.6.0_29, java.vendor=Sun Microsystems Inc.}
no deletions
test: open reader.........OK
test: fields..............OK [80 fields]
test: field norms.........OK [80 fields]
test: terms, freq, prox...ERROR [term inheritedmailtolevel1:giancarlorosario: doc 295226: freq 0 is out of bounds]
java.lang.RuntimeException: term inheritedmailtolevel1:giancarlorosario: doc 295226: freq 0 is out of bounds
at org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:650)
at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
test: stored fields.......ERROR [field data are in wrong format: java.util.zip.DataFormatException: unknown compression method]
org.apache.lucene.index.CorruptIndexException: field data are in wrong format: java.util.zip.DataFormatException: unknown compression method
at org.apache.lucene.index.FieldsReader.uncompress(FieldsReader.java:610)
at org.apache.lucene.index.FieldsReader.addField(FieldsReader.java:368)
at org.apache.lucene.index.FieldsReader.doc(FieldsReader.java:229)
at org.apache.lucene.index.SegmentReader.document(SegmentReader.java:970)
at org.apache.lucene.index.IndexReader.document(IndexReader.java:953)
at org.apache.lucene.index.CheckIndex.testStoredFields(CheckIndex.java:708)
at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:533)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
Caused by: java.util.zip.DataFormatException: unknown compression method
at java.util.zip.Inflater.inflateBytes(Native Method)
at java.util.zip.Inflater.inflate(Inflater.java:238)
at java.util.zip.Inflater.inflate(Inflater.java:256)
at org.apache.lucene.document.CompressionTools.decompress(CompressionTools.java:108)
at org.apache.lucene.index.FieldsReader.uncompress(FieldsReader.java:607)
... 7 more
test: term vectors........OK [0 total vector count; avg 0 term/freq vector fields per doc]
FAILED
WARNING: fixIndex() would remove reference to this segment; full exception:
java.lang.RuntimeException: Term Index test failed
at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
WARNING: 1 broken segments (containing 330424 documents) detected
WARNING: would write new segments file, and 330424 documents would be lost, if -fix were specified
Thanks,
Nishesh
-----Original Message-----
From: Uwe Schindler [mailto:uwe@thetaphi.de]
Sent: Tuesday, November 15, 2011 2:47 AM
To: java-user@lucene.apache.org
Subject: RE: Index Corruption with Lucene 2.9.3
Hi Nishesh,
The index corruption may be caused by one of the bugs in the used JDK
version. From your checkindex output, you are using 1.6.0_02, which is
really old. This Lucene Wiki page lists a lot of bugs in those old JVMs:
http://wiki.apache.org/lucene-java/SunJavaBugs
Many of them may also cause index corruption, especially if you also use
special JVM parameters like -XX:+AggressiveOpts. Please update to JDK
1.6.0_29 (released in October) and report back, if this fixes your issue.
Please don't use any special JVM parameters like -XX:+AggressiveOpts unless
needed and extensively tested (like setting min/max heap).
Uwe
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> Sent: Tuesday, November 15, 2011 1:38 AM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> Thanks Uwe for your comments.
>
> Few points to note for our setup -
> 1) At any time only one thread will be adding index and merging with the
final
> index. Two threads will not concurrently be doing addindex and merge.
> 2) In the current setup where I am seeing the corruption, only one process
is
> working on the final index, so network file system flushing and
consistency
> should not be an issue.
> 3) Since the index sizes are large and because of failover requirements we
> cannot have the final index on local disk, it has to be on a filer.
>
> Regards,
> Nishesh
>
>
> -----Original Message-----
> From: Uwe Schindler [mailto:uwe@thetaphi.de]
> Sent: Monday, November 14, 2011 2:39 PM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> One addition:
>
> Maybe you should update your antique Java version from the year 2007
> (1.6.0_02) to something more up-to-date and maybe use 64 bit with mmap on
a
> local filesystem for such a large index.
>
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
>
>
> > -----Original Message-----
> > From: Uwe Schindler [mailto:uwe@thetaphi.de]
> > Sent: Monday, November 14, 2011 11:33 PM
> > To: java-user@lucene.apache.org
> > Subject: RE: Index Corruption with Lucene 2.9.3
> >
> > Hi,
> >
> > In general it's a bad idea to use Lucene on network-mounted drives.
> > E.g.,
> NFS is
> > heavily broken with the file locking used by Lucene (NIO does not work
> > at
> all,
> > and file-based lock support fails because directory updated may not be
> visible
> > at all times, or are visible before files are flushed - happens-before
> > is
> violated).
> >
> > This can lead to index corruption; you should use local disks,
> > especially
> as they
> > are much faster.
> >
> > -----
> > Uwe Schindler
> > H.-H.-Meier-Allee 63, D-28213 Bremen
> > http://www.thetaphi.de
> > eMail: uwe@thetaphi.de
> >
> >
> > > -----Original Message-----
> > > From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> > > Sent: Monday, November 14, 2011 10:37 PM
> > > To: java-user@lucene.apache.org
> > > Subject: Index Corruption with Lucene 2.9.3
> > >
> > > We are seeing Index corruption very often with version 2.9.3. Our
> > > indexing process is on Linux ( centos 5 ). Index is created on a
> > > mounted drive
> > which is a
> > > shared drive from Windows 2008 server running in a VM. We generally
> > > see index corruption in merge or optimize after indexing runs
> > > continuously for
> > 6-7
> > > hrs with index size reaching around 7-8GB. To reproduce the
> > > corruptions sooner, I have placed the merge ( maybemerge ) call
> > > immediately after addIndex is called. We have a final index which is
> > > in the mounted drive,
> > we
> > > always add documents to an local intermediate index and then call
> > > add
> > index
> > > and merge to the final index.
> > >
> > > The exception that I get -
> > >
> > > 2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204
> > > FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard
> > > 0, guid 10.10.176.148-1321045422606-204: Error in
> > > addIndex()/kazMaybeMerge():
> > > /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException:
> > > background merge hit exception: _1t:c262436
> > > _10.10.176.148-1321045422606-
> > > 204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
> > >
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
> > >
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
> > >
> > > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
> > >
> > > org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652
> > > )
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > rI
> > > nde
> > > x(MergerContext.java:1004)
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > rI
> > > nde
> > > x(MergerContext.java:1094)
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > r(
> > > Me
> > > rgerContext.java:1140)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompr
> > > essModifier.java:375)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompress
> > > Modifier.java:181)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompress
> > > Modifier.java:106)
> > >
> > > com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
> > >
> > >
> > > CheckIndex command shows the following output -
> > >
> > > NOTE: testing will be more thorough if you run java with '-
> > > ea:org.apache.lucene...', so assertions are enabled
> > >
> > > Opening index @ .
> > >
> > > Segments file=segments_23 numSegments=1
> > version=FORMAT_DIAGNOSTICS
> > > [Lucene 2.9]
> > > 1 of 1: name=_1t docCount=262436
> > > compound=true
> > > hasProx=true
> > > numFiles=1
> > > size (MB)=937.835
> > > diagnostics = {optimize=true, mergeFactor=2,
> > os.version=2.6.18-92.1.18.el5,
> > > os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev,
> > > source=merge, os.arch=i386, java.version=1.6.0_02, java.vendor=Sun
> Microsystems Inc.}
> > > no deletions
> > > test: open reader.........OK
> > > test: fields..............OK [79 fields]
> > > test: field norms.........OK [79 fields]
> > > test: terms, freq, prox...ERROR [term fulltext:creativecommons:
> > > doc
> > 262603
> > > >= maxDoc 262436]
> > > java.lang.RuntimeException: term fulltext:creativecommons: doc
> > > 262603
> > > >= maxDoc 262436
> > > at
> > org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
> > > at
> org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
> > > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > > test: stored fields.......OK [524872 total field count; avg 2
> > > fields
> > per doc]
> > > test: term vectors........OK [0 total vector count; avg 0
> > > term/freq
> > vector fields
> > > per doc] FAILED
> > > WARNING: fixIndex() would remove reference to this segment; full
> > > exception:
> > > java.lang.RuntimeException: Term Index test failed
> > > at
> org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
> > > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > >
> > > WARNING: 1 broken segments (containing 262436 documents) detected
> > > WARNING: would write new segments file, and 262436 documents would
> > > be lost, if -fix were specified
> > >
> > >
> > >
> > > Lucene Indexwriter infostream around the corrupt segment _1t shows -
> > >
> > > 9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > > apache.lucene.index.LogByteSizeMergePolicy@2ac02f<mailto:apache.luce
> > > ne
> > > .in
> > > dex.LogByteSizeMergePolicy@2ac02f>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > > heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
> > > 9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > > 361_0:cx1359**
> > > 9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > > 361_0:cx1359**
> > > 9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1s:c261077 _10. 10.176.148-
> 1321053007682-
> > > 361_0:cx1359 [optimize] [total 1 pending]
> > > 9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1s:c261077 _10.10.176.148-132
> > 1053007682-361_0:cx1359**
> > > 9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > > 9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9642 IW 130 [Lucene Merge Thread #0]: now merge
> > > 9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> > into
> > > _1t [optimize] [mergeDocStores]
> > > 9644
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<mailto:m
> > > erge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb>
> > > 9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > > 9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077
> > _10.10.176.148-
> > > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > > 9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
> > > 9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > > 361_0:cx1359**
> > > 9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes
> _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > > [mergeDocStores]
> > > 9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > > 9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > > 9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > > 9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > > 9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > > 9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > > 9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > > 9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > > 9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
> > > 9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > commit transaction
> > > 9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > > 9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=4
> > > 9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > sync _1t.cfs
> > > 9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > done all syncs
> > > 9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1v"
> > > 9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > > 9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1u"
> > > 9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "_1s.cfs"
> > > 9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "segments_1u"
> > > 9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: findMerges: 1 segments
> > > 9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: level 8.242726 to 8.992726: 1 segment s
> > > 9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > skip startCommit(): no changes pending
> > > 9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit == null; skip
> > > 9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > >
> >
> index.KeepOnlyLastCommitDeletionPolicy@28cdb8<mailto:index.KeepOnlyLas
> > > t
> > > CommitDeletionPolicy@28cdb8>
> > > 9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/se
> > > co
> > > nd
> > > ary autoCommit=true mergePolicy=or
> > > g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<mailto:g.apache.
> > > lu ce ne.index.LogByteSizeMergePolicy@da05c8>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMerge
> > > Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
> > > 9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > > 361_0:cx1359**
> > > 9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > > 361_0:cx1359**
> > > 9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1s:c261077 _10. 10.176.148-
> 1321053007682-
> > > 361_0:cx1359 [optimize] [total 1 pending]
> > > 9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1s:c261077 _10.10.176.148-132
> > 1053007682-361_0:cx1359**
> > > 9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > > 9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9716 IW 131 [Lucene Merge Thread #0]: now merge
> > > 9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> > into
> > > _1t [optimize] [mergeDocStores]
> > > 9718
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<mailto:me
> > > rge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f>
> > > 9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > > 9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077
> > _10.10.176.148-
> > > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > > 9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
> > > 9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > > 361_0:cx1359**
> > > 9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes
> _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > > [mergeDocStores]
> > > 9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > > 9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > > 9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > > 9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > > 9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > > 9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > > 9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > > 9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > > 9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
> > > 9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > commit transaction
> > > 9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > > 9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=4
> > > 9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > sync _1t.cfs
> > > 9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > done all syncs
> > > 9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1v"
> > > 9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > > 9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1u"
> > > 9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "_1s.cfs"
> > > 9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "segments_1u"
> > > 9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: findMerges: 1 segments
> > > 9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: level 7.2867203 to 8.03672: 1 segment s
> > > 9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > skip startCommit(): no changes pending
> > > 9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit == null; skip
> > > 9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > > index.KeepOnlyLastCommitDeletionPolicy@8506f9<mailto:index.KeepOnlyL
> > > as
> > > t
> > > CommitDeletionPolicy@8506f9>
> > > 9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > >
> >
> apache.lucene.index.LogByteSizeMergePolicy@18d0653<mailto:apache.lucene.
> > > index.LogByteSizeMergePolicy@18d0653>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeS
> > > cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
> > > 9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-
> > > 204_0:cx4000**
> > > 9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436 _10.10.176. 148-1321045422606-
> > > 204_0:cx4000**
> > > 9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1t:c262436 _10. 10.176.148-
> 1321045422606-
> > > 204_0:cx4000 [optimize] [total 1 pending]
> > > 9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436 _10.10.176.148-132
> > 1045422606-204_0:cx4000**
> > > 9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-
> > > 204_0:cx4000 into _1u [optimize] [mergeDocStores]
> > > 9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9790 IW 132 [Lucene Merge Thread #0]: now merge
> > > 9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000
> > into
> > > _1u [optimize] [mergeDocStores]
> > > 9792
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<mailto:mer
> > > ge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25>
> > > 9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
> > > 9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436
> > _10.10.176.148-
> > > 1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
> > > 9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
> > > 9796 IW 132 [Lucene Merge Thread #0]: handleMergeException:
> > > merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into
> > > _1u [optimize] [mergeDocStores]
> > > exc=org.apache.lucene.index.CorruptIndexException: docs out of
> order
> > > (262439 <= 2096427 )
> > > 9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
> > > 9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fdt"
> > > 9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
> > > 9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fdx"
> > > 9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
> > > 9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fnm"
> > > 9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
> > > 9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.frq"
> > > 9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
> > > 9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.prx"
> > > 9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
> > > 9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.tii"
> > > 9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
> > > 9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.tis"
> > > 9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
> > > 9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > rollback transaction
> > > 9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > all
> > > running merges have aborted
> > > 9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = false]
> > > 9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=1
> > > 9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > done all syncs
> > > 9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1w"
> > > 9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > > checkpoint "segments_1w" [1 segments ; isCo mmit = true]
> > > 9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1v"
> > > 9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > delete
> > > "segments_1v"
> > > 9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: done
> > > 9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > >
> >
> index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<mailto:index.KeepOnlyLa
> > > s
> > > tCommitDeletionPolicy@1ec4b8e>
> > > 9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > > apache.lucene.index.LogByteSizeMergePolicy@546a0e<mailto:apache.luce
> > > ne
> > > .i
> > > ndex.LogByteSizeMergePolicy@546a0e>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > > heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
> > > 9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > start transaction
> >
> >
> > ---------------------------------------------------------------------
> > 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
>
>
>
> ---------------------------------------------------------------------
> 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
---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org
RE: Index Corruption with Lucene 2.9.3
Posted by Uwe Schindler <uw...@thetaphi.de>.
Hi Nishesh,
The index corruption may be caused by one of the bugs in the used JDK
version. From your checkindex output, you are using 1.6.0_02, which is
really old. This Lucene Wiki page lists a lot of bugs in those old JVMs:
http://wiki.apache.org/lucene-java/SunJavaBugs
Many of them may also cause index corruption, especially if you also use
special JVM parameters like -XX:+AggressiveOpts. Please update to JDK
1.6.0_29 (released in October) and report back, if this fixes your issue.
Please don't use any special JVM parameters like -XX:+AggressiveOpts unless
needed and extensively tested (like setting min/max heap).
Uwe
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> Sent: Tuesday, November 15, 2011 1:38 AM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> Thanks Uwe for your comments.
>
> Few points to note for our setup -
> 1) At any time only one thread will be adding index and merging with the
final
> index. Two threads will not concurrently be doing addindex and merge.
> 2) In the current setup where I am seeing the corruption, only one process
is
> working on the final index, so network file system flushing and
consistency
> should not be an issue.
> 3) Since the index sizes are large and because of failover requirements we
> cannot have the final index on local disk, it has to be on a filer.
>
> Regards,
> Nishesh
>
>
> -----Original Message-----
> From: Uwe Schindler [mailto:uwe@thetaphi.de]
> Sent: Monday, November 14, 2011 2:39 PM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> One addition:
>
> Maybe you should update your antique Java version from the year 2007
> (1.6.0_02) to something more up-to-date and maybe use 64 bit with mmap on
a
> local filesystem for such a large index.
>
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
>
>
> > -----Original Message-----
> > From: Uwe Schindler [mailto:uwe@thetaphi.de]
> > Sent: Monday, November 14, 2011 11:33 PM
> > To: java-user@lucene.apache.org
> > Subject: RE: Index Corruption with Lucene 2.9.3
> >
> > Hi,
> >
> > In general it's a bad idea to use Lucene on network-mounted drives.
> > E.g.,
> NFS is
> > heavily broken with the file locking used by Lucene (NIO does not work
> > at
> all,
> > and file-based lock support fails because directory updated may not be
> visible
> > at all times, or are visible before files are flushed - happens-before
> > is
> violated).
> >
> > This can lead to index corruption; you should use local disks,
> > especially
> as they
> > are much faster.
> >
> > -----
> > Uwe Schindler
> > H.-H.-Meier-Allee 63, D-28213 Bremen
> > http://www.thetaphi.de
> > eMail: uwe@thetaphi.de
> >
> >
> > > -----Original Message-----
> > > From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> > > Sent: Monday, November 14, 2011 10:37 PM
> > > To: java-user@lucene.apache.org
> > > Subject: Index Corruption with Lucene 2.9.3
> > >
> > > We are seeing Index corruption very often with version 2.9.3. Our
> > > indexing process is on Linux ( centos 5 ). Index is created on a
> > > mounted drive
> > which is a
> > > shared drive from Windows 2008 server running in a VM. We generally
> > > see index corruption in merge or optimize after indexing runs
> > > continuously for
> > 6-7
> > > hrs with index size reaching around 7-8GB. To reproduce the
> > > corruptions sooner, I have placed the merge ( maybemerge ) call
> > > immediately after addIndex is called. We have a final index which is
> > > in the mounted drive,
> > we
> > > always add documents to an local intermediate index and then call
> > > add
> > index
> > > and merge to the final index.
> > >
> > > The exception that I get -
> > >
> > > 2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204
> > > FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard
> > > 0, guid 10.10.176.148-1321045422606-204: Error in
> > > addIndex()/kazMaybeMerge():
> > > /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException:
> > > background merge hit exception: _1t:c262436
> > > _10.10.176.148-1321045422606-
> > > 204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
> > >
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
> > >
org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
> > >
> > > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
> > >
> > > org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652
> > > )
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > rI
> > > nde
> > > x(MergerContext.java:1004)
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > rI
> > > nde
> > > x(MergerContext.java:1094)
> > >
> > > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFile
> > > r(
> > > Me
> > > rgerContext.java:1140)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompr
> > > essModifier.java:375)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompress
> > > Modifier.java:181)
> > >
> > > com.kazeon.search.indexingengine.statemachine.modifiers.merger.Local
> > > In
> > > dex
> > >
> >
> OptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompress
> > > Modifier.java:106)
> > >
> > > com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
> > >
> > >
> > > CheckIndex command shows the following output -
> > >
> > > NOTE: testing will be more thorough if you run java with '-
> > > ea:org.apache.lucene...', so assertions are enabled
> > >
> > > Opening index @ .
> > >
> > > Segments file=segments_23 numSegments=1
> > version=FORMAT_DIAGNOSTICS
> > > [Lucene 2.9]
> > > 1 of 1: name=_1t docCount=262436
> > > compound=true
> > > hasProx=true
> > > numFiles=1
> > > size (MB)=937.835
> > > diagnostics = {optimize=true, mergeFactor=2,
> > os.version=2.6.18-92.1.18.el5,
> > > os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev,
> > > source=merge, os.arch=i386, java.version=1.6.0_02, java.vendor=Sun
> Microsystems Inc.}
> > > no deletions
> > > test: open reader.........OK
> > > test: fields..............OK [79 fields]
> > > test: field norms.........OK [79 fields]
> > > test: terms, freq, prox...ERROR [term fulltext:creativecommons:
> > > doc
> > 262603
> > > >= maxDoc 262436]
> > > java.lang.RuntimeException: term fulltext:creativecommons: doc
> > > 262603
> > > >= maxDoc 262436
> > > at
> > org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
> > > at
> org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
> > > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > > test: stored fields.......OK [524872 total field count; avg 2
> > > fields
> > per doc]
> > > test: term vectors........OK [0 total vector count; avg 0
> > > term/freq
> > vector fields
> > > per doc] FAILED
> > > WARNING: fixIndex() would remove reference to this segment; full
> > > exception:
> > > java.lang.RuntimeException: Term Index test failed
> > > at
> org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
> > > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > >
> > > WARNING: 1 broken segments (containing 262436 documents) detected
> > > WARNING: would write new segments file, and 262436 documents would
> > > be lost, if -fix were specified
> > >
> > >
> > >
> > > Lucene Indexwriter infostream around the corrupt segment _1t shows -
> > >
> > > 9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > > apache.lucene.index.LogByteSizeMergePolicy@2ac02f<mailto:apache.luce
> > > ne
> > > .in
> > > dex.LogByteSizeMergePolicy@2ac02f>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > > heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
> > > 9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > > 361_0:cx1359**
> > > 9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > > 361_0:cx1359**
> > > 9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1s:c261077 _10. 10.176.148-
> 1321053007682-
> > > 361_0:cx1359 [optimize] [total 1 pending]
> > > 9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1s:c261077 _10.10.176.148-132
> > 1053007682-361_0:cx1359**
> > > 9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > > 9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9642 IW 130 [Lucene Merge Thread #0]: now merge
> > > 9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> > into
> > > _1t [optimize] [mergeDocStores]
> > > 9644
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<mailto:m
> > > erge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb>
> > > 9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > > 9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077
> > _10.10.176.148-
> > > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > > 9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
> > > 9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > > 361_0:cx1359**
> > > 9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes
> _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > > [mergeDocStores]
> > > 9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > > 9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > > 9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > > 9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > > 9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > > 9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > > 9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > > 9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > > 9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
> > > 9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > commit transaction
> > > 9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > > 9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=4
> > > 9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > sync _1t.cfs
> > > 9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > done all syncs
> > > 9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1v"
> > > 9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > > 9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1u"
> > > 9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "_1s.cfs"
> > > 9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "segments_1u"
> > > 9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: findMerges: 1 segments
> > > 9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: level 8.242726 to 8.992726: 1 segment s
> > > 9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > skip startCommit(): no changes pending
> > > 9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit == null; skip
> > > 9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > >
> >
> index.KeepOnlyLastCommitDeletionPolicy@28cdb8<mailto:index.KeepOnlyLas
> > > t
> > > CommitDeletionPolicy@28cdb8>
> > > 9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/se
> > > co
> > > nd
> > > ary autoCommit=true mergePolicy=or
> > > g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<mailto:g.apache.
> > > lu ce ne.index.LogByteSizeMergePolicy@da05c8>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMerge
> > > Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
> > > 9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077
> > > 9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > > 361_0:cx1359**
> > > 9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > > 361_0:cx1359**
> > > 9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1s:c261077 _10. 10.176.148-
> 1321053007682-
> > > 361_0:cx1359 [optimize] [total 1 pending]
> > > 9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1s:c261077 _10.10.176.148-132
> > 1053007682-361_0:cx1359**
> > > 9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > > 9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9716 IW 131 [Lucene Merge Thread #0]: now merge
> > > 9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> > into
> > > _1t [optimize] [mergeDocStores]
> > > 9718
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<mailto:me
> > > rge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f>
> > > 9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > > 9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077
> > _10.10.176.148-
> > > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > > 9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
> > > 9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > > 361_0:cx1359**
> > > 9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes
> _1s:c261077
> > > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > > [mergeDocStores]
> > > 9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > > segments ; isCommit = false]
> > > 9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > > 9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > > 9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > > 9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > > 9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > > 9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > > 9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > > 9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > > 9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
> > > 9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > commit transaction
> > > 9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > > 9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=4
> > > 9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > sync _1t.cfs
> > > 9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > done all syncs
> > > 9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1v"
> > > 9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > > 9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1u"
> > > 9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "_1s.cfs"
> > > 9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > delete
> > > "segments_1u"
> > > 9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: findMerges: 1 segments
> > > 9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > LMP: level 7.2867203 to 8.03672: 1 segment s
> > > 9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > skip startCommit(): no changes pending
> > > 9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: pendingCommit == null; skip
> > > 9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > commit: done
> > > 9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > > index.KeepOnlyLastCommitDeletionPolicy@8506f9<mailto:index.KeepOnlyL
> > > as
> > > t
> > > CommitDeletionPolicy@8506f9>
> > > 9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > >
> >
> apache.lucene.index.LogByteSizeMergePolicy@18d0653<mailto:apache.lucene.
> > > index.LogByteSizeMergePolicy@18d0653>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeS
> > > cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
> > > 9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > start transaction
> > > 9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at startTransaction
> > > 9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-
> > > 204_0:cx4000**
> > > 9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436 _10.10.176. 148-1321045422606-
> > > 204_0:cx4000**
> > > 9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > add
> > > merge to pendingMerges: _1t:c262436 _10. 10.176.148-
> 1321045422606-
> > > 204_0:cx4000 [optimize] [total 1 pending]
> > > 9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436 _10.10.176.148-132
> > 1045422606-204_0:cx4000**
> > > 9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-
> > > 204_0:cx4000 into _1u [optimize] [mergeDocStores]
> > > 9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: launch new thread [Lucene Merge Thr ead #0]
> > > 9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
> > > 9790 IW 132 [Lucene Merge Thread #0]: now merge
> > > 9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000
> > into
> > > _1u [optimize] [mergeDocStores]
> > > 9792
> > >
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<mailto:mer
> > > ge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25>
> > > 9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
> > > 9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436
> > _10.10.176.148-
> > > 1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
> > > 9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
> > > 9796 IW 132 [Lucene Merge Thread #0]: handleMergeException:
> > > merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into
> > > _1u [optimize] [mergeDocStores]
> > > exc=org.apache.lucene.index.CorruptIndexException: docs out of
> order
> > > (262439 <= 2096427 )
> > > 9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
> > > 9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fdt"
> > > 9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
> > > 9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fdx"
> > > 9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
> > > 9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.fnm"
> > > 9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
> > > 9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.frq"
> > > 9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
> > > 9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.prx"
> > > 9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
> > > 9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.tii"
> > > 9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
> > > 9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > > newly created unreferenced file "_1u.tis"
> > > 9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
> > > 9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > rollback transaction
> > > 9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > all
> > > running merges have aborted
> > > 9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > > checkpoint "segments_1v" [1 segments ; isCo mmit = false]
> > > 9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > flush at close
> > > 9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: now merge
> > > 9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: index: _1t:c262436
> > > 9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > CMS: no more merges pending; now return
> > > 9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > call final commit()
> > > 9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > startCommit(): start sizeInBytes=0
> > > 9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > startCommit index=_1t:c262436 changeCount=1
> > > 9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > done all syncs
> > > 9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: pendingCommit != null
> > > 9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: wrote segments file "segments_1w"
> > > 9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > > checkpoint "segments_1w" [1 segments ; isCo mmit = true]
> > > 9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > deleteCommits: now decRef commit "segments_1v"
> > > 9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > delete
> > > "segments_1v"
> > > 9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > commit: done
> > > 9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > at
> > > close: _1t:c262436
> > > 9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream deletionPolicy=org.apache.lucene.
> > >
> >
> index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<mailto:index.KeepOnlyLa
> > > s
> > > tCommitDeletionPolicy@1ec4b8e>
> > > 9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setInfoStream: dir=org.apache.lucene.store.S
> > > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/pr
> > > im
> > > ary
> > > autoCommit=true mergePolicy=org.
> > > apache.lucene.index.LogByteSizeMergePolicy@546a0e<mailto:apache.luce
> > > ne
> > > .i
> > > ndex.LogByteSizeMergePolicy@546a0e>
> > > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > > heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > > maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
> > > 9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > setMaxBufferedDocs 10000
> > > 9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush at addIndexes
> > > 9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: now pause all indexing threads
> > > 9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > > numBufDelTerms=0
> > > 9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > > index before flush _1t:c262436
> > > 9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > now
> > > start transaction
> >
> >
> > ---------------------------------------------------------------------
> > 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
>
>
>
> ---------------------------------------------------------------------
> 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: Index Corruption with Lucene 2.9.3
Posted by ni...@emc.com.
Thanks Uwe for your comments.
Few points to note for our setup -
1) At any time only one thread will be adding index and merging with the final index. Two threads will not concurrently be doing addindex and merge.
2) In the current setup where I am seeing the corruption, only one process is working on the final index, so network file system flushing and consistency should not be an issue.
3) Since the index sizes are large and because of failover requirements we cannot have the final index on local disk, it has to be on a filer.
Regards,
Nishesh
-----Original Message-----
From: Uwe Schindler [mailto:uwe@thetaphi.de]
Sent: Monday, November 14, 2011 2:39 PM
To: java-user@lucene.apache.org
Subject: RE: Index Corruption with Lucene 2.9.3
One addition:
Maybe you should update your antique Java version from the year 2007
(1.6.0_02) to something more up-to-date and maybe use 64 bit with mmap on a
local filesystem for such a large index.
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: Uwe Schindler [mailto:uwe@thetaphi.de]
> Sent: Monday, November 14, 2011 11:33 PM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> Hi,
>
> In general it's a bad idea to use Lucene on network-mounted drives. E.g.,
NFS is
> heavily broken with the file locking used by Lucene (NIO does not work at
all,
> and file-based lock support fails because directory updated may not be
visible
> at all times, or are visible before files are flushed - happens-before is
violated).
>
> This can lead to index corruption; you should use local disks, especially
as they
> are much faster.
>
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
>
>
> > -----Original Message-----
> > From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> > Sent: Monday, November 14, 2011 10:37 PM
> > To: java-user@lucene.apache.org
> > Subject: Index Corruption with Lucene 2.9.3
> >
> > We are seeing Index corruption very often with version 2.9.3. Our
> > indexing process is on Linux ( centos 5 ). Index is created on a
> > mounted drive
> which is a
> > shared drive from Windows 2008 server running in a VM. We generally
> > see index corruption in merge or optimize after indexing runs
> > continuously for
> 6-7
> > hrs with index size reaching around 7-8GB. To reproduce the
> > corruptions sooner, I have placed the merge ( maybemerge ) call
> > immediately after addIndex is called. We have a final index which is
> > in the mounted drive,
> we
> > always add documents to an local intermediate index and then call add
> index
> > and merge to the final index.
> >
> > The exception that I get -
> >
> > 2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204
> > FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard
> > 0, guid 10.10.176.148-1321045422606-204: Error in
> > addIndex()/kazMaybeMerge():
> > /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException:
> > background merge hit exception: _1t:c262436
> > _10.10.176.148-1321045422606-
> > 204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
> >
> > org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerI
> > nde
> > x(MergerContext.java:1004)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerI
> > nde
> > x(MergerContext.java:1094)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFiler(
> > Me
> > rgerContext.java:1140)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompr
> > essModifier.java:375)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompress
> > Modifier.java:181)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompress
> > Modifier.java:106)
> > com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
> >
> >
> > CheckIndex command shows the following output -
> >
> > NOTE: testing will be more thorough if you run java with '-
> > ea:org.apache.lucene...', so assertions are enabled
> >
> > Opening index @ .
> >
> > Segments file=segments_23 numSegments=1
> version=FORMAT_DIAGNOSTICS
> > [Lucene 2.9]
> > 1 of 1: name=_1t docCount=262436
> > compound=true
> > hasProx=true
> > numFiles=1
> > size (MB)=937.835
> > diagnostics = {optimize=true, mergeFactor=2,
> os.version=2.6.18-92.1.18.el5,
> > os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev, source=merge,
> > os.arch=i386, java.version=1.6.0_02, java.vendor=Sun Microsystems Inc.}
> > no deletions
> > test: open reader.........OK
> > test: fields..............OK [79 fields]
> > test: field norms.........OK [79 fields]
> > test: terms, freq, prox...ERROR [term fulltext:creativecommons:
> > doc
> 262603
> > >= maxDoc 262436]
> > java.lang.RuntimeException: term fulltext:creativecommons: doc 262603
> > >= maxDoc 262436
> > at
> org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
> > at
org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
> > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > test: stored fields.......OK [524872 total field count; avg 2
> > fields
> per doc]
> > test: term vectors........OK [0 total vector count; avg 0
> > term/freq
> vector fields
> > per doc] FAILED
> > WARNING: fixIndex() would remove reference to this segment; full
> > exception:
> > java.lang.RuntimeException: Term Index test failed
> > at
org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
> > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> >
> > WARNING: 1 broken segments (containing 262436 documents) detected
> > WARNING: would write new segments file, and 262436 documents would be
> > lost, if -fix were specified
> >
> >
> >
> > Lucene Indexwriter infostream around the corrupt segment _1t shows -
> >
> > 9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> > apache.lucene.index.LogByteSizeMergePolicy@2ac02f<mailto:apache.lucene
> > .in
> > dex.LogByteSizeMergePolicy@2ac02f>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
> > 9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at addIndexes
> > 9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > start transaction
> > 9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at startTransaction
> > 9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > 361_0:cx1359**
> > 9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > 361_0:cx1359**
> > 9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> > 361_0:cx1359 [optimize] [total 1 pending]
> > 9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1s:c261077 _10.10.176.148-132
> 1053007682-361_0:cx1359**
> > 9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > 9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9642 IW 130 [Lucene Merge Thread #0]: now merge
> > 9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> into
> > _1t [optimize] [mergeDocStores]
> > 9644
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<mailto:m
> > erge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb>
> > 9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > 9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077
> _10.10.176.148-
> > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > 9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
> > 9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > 361_0:cx1359**
> > 9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > [mergeDocStores]
> > 9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > 9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > 9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > 9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > 9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > 9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > 9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > 9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > 9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
> > 9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > commit transaction
> > 9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > 9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=4
> > 9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > sync _1t.cfs
> > 9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > done all syncs
> > 9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1v"
> > 9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > 9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1u"
> > 9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "_1s.cfs"
> > 9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "segments_1u"
> > 9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: findMerges: 1 segments
> > 9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: level 8.242726 to 8.992726: 1 segment s
> > 9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > flush at close
> > 9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > call final commit()
> > 9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > skip startCommit(): no changes pending
> > 9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit == null; skip
> > 9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> >
> index.KeepOnlyLastCommitDeletionPolicy@28cdb8<mailto:index.KeepOnlyLas
> > t
> > CommitDeletionPolicy@28cdb8>
> > 9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/seco
> > nd
> > ary autoCommit=true mergePolicy=or
> > g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<mailto:g.apache.lu
> > ce ne.index.LogByteSizeMergePolicy@da05c8>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMerge
> > Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
> > 9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at addIndexes
> > 9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > start transaction
> > 9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at startTransaction
> > 9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > 361_0:cx1359**
> > 9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > 361_0:cx1359**
> > 9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> > 361_0:cx1359 [optimize] [total 1 pending]
> > 9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1s:c261077 _10.10.176.148-132
> 1053007682-361_0:cx1359**
> > 9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > 9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9716 IW 131 [Lucene Merge Thread #0]: now merge
> > 9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> into
> > _1t [optimize] [mergeDocStores]
> > 9718
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<mailto:me
> > rge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f>
> > 9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > 9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077
> _10.10.176.148-
> > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > 9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
> > 9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > 361_0:cx1359**
> > 9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > [mergeDocStores]
> > 9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > 9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > 9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > 9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > 9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > 9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > 9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > 9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > 9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
> > 9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > commit transaction
> > 9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > 9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=4
> > 9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > sync _1t.cfs
> > 9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > done all syncs
> > 9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1v"
> > 9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > 9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1u"
> > 9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "_1s.cfs"
> > 9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "segments_1u"
> > 9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: findMerges: 1 segments
> > 9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: level 7.2867203 to 8.03672: 1 segment s
> > 9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > flush at close
> > 9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > call final commit()
> > 9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > skip startCommit(): no changes pending
> > 9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit == null; skip
> > 9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> > index.KeepOnlyLastCommitDeletionPolicy@8506f9<mailto:index.KeepOnlyLas
> > t
> > CommitDeletionPolicy@8506f9>
> > 9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> >
> apache.lucene.index.LogByteSizeMergePolicy@18d0653<mailto:apache.lucene.
> > index.LogByteSizeMergePolicy@18d0653>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeS
> > cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
> > 9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at addIndexes
> > 9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > start transaction
> > 9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at startTransaction
> > 9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-
> > 204_0:cx4000**
> > 9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436 _10.10.176. 148-1321045422606-
> > 204_0:cx4000**
> > 9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1t:c262436 _10. 10.176.148-1321045422606-
> > 204_0:cx4000 [optimize] [total 1 pending]
> > 9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: now merge
> > 9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: index: _1t:c262436 _10.10.176.148-132
> 1045422606-204_0:cx4000**
> > 9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-
> > 204_0:cx4000 into _1u [optimize] [mergeDocStores]
> > 9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9790 IW 132 [Lucene Merge Thread #0]: now merge
> > 9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000
> into
> > _1u [optimize] [mergeDocStores]
> > 9792
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<mailto:mer
> > ge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25>
> > 9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
> > 9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436
> _10.10.176.148-
> > 1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
> > 9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
> > 9796 IW 132 [Lucene Merge Thread #0]: handleMergeException:
> > merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into
> > _1u [optimize] [mergeDocStores]
> > exc=org.apache.lucene.index.CorruptIndexException: docs out of
order
> > (262439 <= 2096427 )
> > 9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
> > 9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fdt"
> > 9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
> > 9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fdx"
> > 9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
> > 9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fnm"
> > 9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
> > 9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.frq"
> > 9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
> > 9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.prx"
> > 9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
> > 9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.tii"
> > 9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
> > 9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.tis"
> > 9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
> > 9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > rollback transaction
> > 9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> all
> > running merges have aborted
> > 9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = false]
> > 9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > flush at close
> > 9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: now merge
> > 9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > call final commit()
> > 9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=1
> > 9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > done all syncs
> > 9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1w"
> > 9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > checkpoint "segments_1w" [1 segments ; isCo mmit = true]
> > 9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1v"
> > 9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> delete
> > "segments_1v"
> > 9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: done
> > 9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> >
> index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<mailto:index.KeepOnlyLa
> > s
> > tCommitDeletionPolicy@1ec4b8e>
> > 9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> > apache.lucene.index.LogByteSizeMergePolicy@546a0e<mailto:apache.lucene
> > .i
> > ndex.LogByteSizeMergePolicy@546a0e>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
> > 9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at addIndexes
> > 9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > start transaction
>
>
> ---------------------------------------------------------------------
> 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
---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org
RE: Index Corruption with Lucene 2.9.3
Posted by Uwe Schindler <uw...@thetaphi.de>.
One addition:
Maybe you should update your antique Java version from the year 2007
(1.6.0_02) to something more up-to-date and maybe use 64 bit with mmap on a
local filesystem for such a large index.
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: Uwe Schindler [mailto:uwe@thetaphi.de]
> Sent: Monday, November 14, 2011 11:33 PM
> To: java-user@lucene.apache.org
> Subject: RE: Index Corruption with Lucene 2.9.3
>
> Hi,
>
> In general it's a bad idea to use Lucene on network-mounted drives. E.g.,
NFS is
> heavily broken with the file locking used by Lucene (NIO does not work at
all,
> and file-based lock support fails because directory updated may not be
visible
> at all times, or are visible before files are flushed - happens-before is
violated).
>
> This can lead to index corruption; you should use local disks, especially
as they
> are much faster.
>
> -----
> Uwe Schindler
> H.-H.-Meier-Allee 63, D-28213 Bremen
> http://www.thetaphi.de
> eMail: uwe@thetaphi.de
>
>
> > -----Original Message-----
> > From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> > Sent: Monday, November 14, 2011 10:37 PM
> > To: java-user@lucene.apache.org
> > Subject: Index Corruption with Lucene 2.9.3
> >
> > We are seeing Index corruption very often with version 2.9.3. Our
> > indexing process is on Linux ( centos 5 ). Index is created on a
> > mounted drive
> which is a
> > shared drive from Windows 2008 server running in a VM. We generally
> > see index corruption in merge or optimize after indexing runs
> > continuously for
> 6-7
> > hrs with index size reaching around 7-8GB. To reproduce the
> > corruptions sooner, I have placed the merge ( maybemerge ) call
> > immediately after addIndex is called. We have a final index which is
> > in the mounted drive,
> we
> > always add documents to an local intermediate index and then call add
> index
> > and merge to the final index.
> >
> > The exception that I get -
> >
> > 2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204
> > FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard
> > 0, guid 10.10.176.148-1321045422606-204: Error in
> > addIndex()/kazMaybeMerge():
> > /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException:
> > background merge hit exception: _1t:c262436
> > _10.10.176.148-1321045422606-
> > 204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
> > org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
> >
> > org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerI
> > nde
> > x(MergerContext.java:1004)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerI
> > nde
> > x(MergerContext.java:1094)
> >
> > com.kazeon.search.indexingengine.context.MergerContext.mergeWithFiler(
> > Me
> > rgerContext.java:1140)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompr
> > essModifier.java:375)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompress
> > Modifier.java:181)
> >
> > com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIn
> > dex
> >
> OptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompress
> > Modifier.java:106)
> > com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
> >
> >
> > CheckIndex command shows the following output -
> >
> > NOTE: testing will be more thorough if you run java with '-
> > ea:org.apache.lucene...', so assertions are enabled
> >
> > Opening index @ .
> >
> > Segments file=segments_23 numSegments=1
> version=FORMAT_DIAGNOSTICS
> > [Lucene 2.9]
> > 1 of 1: name=_1t docCount=262436
> > compound=true
> > hasProx=true
> > numFiles=1
> > size (MB)=937.835
> > diagnostics = {optimize=true, mergeFactor=2,
> os.version=2.6.18-92.1.18.el5,
> > os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev, source=merge,
> > os.arch=i386, java.version=1.6.0_02, java.vendor=Sun Microsystems Inc.}
> > no deletions
> > test: open reader.........OK
> > test: fields..............OK [79 fields]
> > test: field norms.........OK [79 fields]
> > test: terms, freq, prox...ERROR [term fulltext:creativecommons:
> > doc
> 262603
> > >= maxDoc 262436]
> > java.lang.RuntimeException: term fulltext:creativecommons: doc 262603
> > >= maxDoc 262436
> > at
> org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
> > at
org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
> > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> > test: stored fields.......OK [524872 total field count; avg 2
> > fields
> per doc]
> > test: term vectors........OK [0 total vector count; avg 0
> > term/freq
> vector fields
> > per doc] FAILED
> > WARNING: fixIndex() would remove reference to this segment; full
> > exception:
> > java.lang.RuntimeException: Term Index test failed
> > at
org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
> > at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> >
> > WARNING: 1 broken segments (containing 262436 documents) detected
> > WARNING: would write new segments file, and 262436 documents would be
> > lost, if -fix were specified
> >
> >
> >
> > Lucene Indexwriter infostream around the corrupt segment _1t shows -
> >
> > 9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> > apache.lucene.index.LogByteSizeMergePolicy@2ac02f<mailto:apache.lucene
> > .in
> > dex.LogByteSizeMergePolicy@2ac02f>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
> > 9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at addIndexes
> > 9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > start transaction
> > 9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at startTransaction
> > 9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > 361_0:cx1359**
> > 9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > 361_0:cx1359**
> > 9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> > 361_0:cx1359 [optimize] [total 1 pending]
> > 9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1s:c261077 _10.10.176.148-132
> 1053007682-361_0:cx1359**
> > 9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > 9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9642 IW 130 [Lucene Merge Thread #0]: now merge
> > 9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> into
> > _1t [optimize] [mergeDocStores]
> > 9644
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<mailto:m
> > erge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb>
> > 9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > 9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077
> _10.10.176.148-
> > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > 9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
> > 9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > 361_0:cx1359**
> > 9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > [mergeDocStores]
> > 9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > 9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > 9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > 9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > 9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > 9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > 9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > 9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > 9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
> > 9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > commit transaction
> > 9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > 9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=4
> > 9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > sync _1t.cfs
> > 9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > done all syncs
> > 9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1v"
> > 9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > 9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1u"
> > 9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "_1s.cfs"
> > 9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "segments_1u"
> > 9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: findMerges: 1 segments
> > 9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: level 8.242726 to 8.992726: 1 segment s
> > 9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > flush at close
> > 9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > call final commit()
> > 9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > skip startCommit(): no changes pending
> > 9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit == null; skip
> > 9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> >
> index.KeepOnlyLastCommitDeletionPolicy@28cdb8<mailto:index.KeepOnlyLas
> > t
> > CommitDeletionPolicy@28cdb8>
> > 9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/seco
> > nd
> > ary autoCommit=true mergePolicy=or
> > g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<mailto:g.apache.lu
> > ce ne.index.LogByteSizeMergePolicy@da05c8>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMerge
> > Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
> > 9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at addIndexes
> > 9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > start transaction
> > 9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush at startTransaction
> > 9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077
> > 9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> > 361_0:cx1359**
> > 9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> > 361_0:cx1359**
> > 9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> > 361_0:cx1359 [optimize] [total 1 pending]
> > 9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1s:c261077 _10.10.176.148-132
> 1053007682-361_0:cx1359**
> > 9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> > 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> > 9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9716 IW 131 [Lucene Merge Thread #0]: now merge
> > 9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359
> into
> > _1t [optimize] [mergeDocStores]
> > 9718
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<mailto:me
> > rge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f>
> > 9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> > 9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077
> _10.10.176.148-
> > 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> > 9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
> > 9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> > [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> > 361_0:cx1359**
> > 9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> > _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> > [mergeDocStores]
> > 9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> > segments ; isCommit = false]
> > 9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> > 9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> > 9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> > 9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> > 9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> > 9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> > 9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> > 9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> > 9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
> > 9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > commit transaction
> > 9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> > 9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=4
> > 9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > sync _1t.cfs
> > 9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > done all syncs
> > 9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1v"
> > 9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> > 9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1u"
> > 9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "_1s.cfs"
> > 9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> delete
> > "segments_1u"
> > 9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: findMerges: 1 segments
> > 9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > LMP: level 7.2867203 to 8.03672: 1 segment s
> > 9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > flush at close
> > 9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: now merge
> > 9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> now
> > call final commit()
> > 9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > skip startCommit(): no changes pending
> > 9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: pendingCommit == null; skip
> > 9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> > commit: done
> > 9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> > index.KeepOnlyLastCommitDeletionPolicy@8506f9<mailto:index.KeepOnlyLas
> > t
> > CommitDeletionPolicy@8506f9>
> > 9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> >
> apache.lucene.index.LogByteSizeMergePolicy@18d0653<mailto:apache.lucene.
> > index.LogByteSizeMergePolicy@18d0653>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeS
> > cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
> > 9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at addIndexes
> > 9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > start transaction
> > 9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at startTransaction
> > 9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-
> > 204_0:cx4000**
> > 9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436 _10.10.176. 148-1321045422606-
> > 204_0:cx4000**
> > 9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> add
> > merge to pendingMerges: _1t:c262436 _10. 10.176.148-1321045422606-
> > 204_0:cx4000 [optimize] [total 1 pending]
> > 9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: now merge
> > 9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: index: _1t:c262436 _10.10.176.148-132
> 1045422606-204_0:cx4000**
> > 9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-
> > 204_0:cx4000 into _1u [optimize] [mergeDocStores]
> > 9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: launch new thread [Lucene Merge Thr ead #0]
> > 9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
> > 9790 IW 132 [Lucene Merge Thread #0]: now merge
> > 9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000
> into
> > _1u [optimize] [mergeDocStores]
> > 9792
> >
> merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<mailto:mer
> > ge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25>
> > 9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
> > 9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436
> _10.10.176.148-
> > 1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
> > 9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
> > 9796 IW 132 [Lucene Merge Thread #0]: handleMergeException:
> > merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into
> > _1u [optimize] [mergeDocStores]
> > exc=org.apache.lucene.index.CorruptIndexException: docs out of
order
> > (262439 <= 2096427 )
> > 9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
> > 9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fdt"
> > 9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
> > 9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fdx"
> > 9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
> > 9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.fnm"
> > 9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
> > 9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.frq"
> > 9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
> > 9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.prx"
> > 9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
> > 9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.tii"
> > 9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
> > 9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing
> > newly created unreferenced file "_1u.tis"
> > 9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
> > 9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > rollback transaction
> > 9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> all
> > running merges have aborted
> > 9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > checkpoint "segments_1v" [1 segments ; isCo mmit = false]
> > 9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > flush at close
> > 9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: now merge
> > 9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: index: _1t:c262436
> > 9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > CMS: no more merges pending; now return
> > 9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > call final commit()
> > 9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > startCommit(): start sizeInBytes=0
> > 9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > startCommit index=_1t:c262436 changeCount=1
> > 9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > done all syncs
> > 9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: pendingCommit != null
> > 9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: wrote segments file "segments_1w"
> > 9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> > checkpoint "segments_1w" [1 segments ; isCo mmit = true]
> > 9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > deleteCommits: now decRef commit "segments_1v"
> > 9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> delete
> > "segments_1v"
> > 9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > commit: done
> > 9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: at
> > close: _1t:c262436
> > 9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream deletionPolicy=org.apache.lucene.
> >
> index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<mailto:index.KeepOnlyLa
> > s
> > tCommitDeletionPolicy@1ec4b8e>
> > 9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setInfoStream: dir=org.apache.lucene.store.S
> > impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/prim
> > ary
> > autoCommit=true mergePolicy=org.
> > apache.lucene.index.LogByteSizeMergePolicy@546a0e<mailto:apache.lucene
> > .i
> > ndex.LogByteSizeMergePolicy@546a0e>
> > mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> > heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> > maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
> > 9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > setMaxBufferedDocs 10000
> > 9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush at addIndexes
> > 9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: now pause all indexing threads
> > 9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > flush: segment=null docStoreSegment=null d ocStoreOffset=0
> > flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> > numBufDelTerms=0
> > 9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> > index before flush _1t:c262436
> > 9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> now
> > start transaction
>
>
> ---------------------------------------------------------------------
> 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: Index Corruption with Lucene 2.9.3
Posted by Uwe Schindler <uw...@thetaphi.de>.
Hi,
In general it's a bad idea to use Lucene on network-mounted drives. E.g.,
NFS is heavily broken with the file locking used by Lucene (NIO does not
work at all, and file-based lock support fails because directory updated may
not be visible at all times, or are visible before files are flushed -
happens-before is violated).
This can lead to index corruption; you should use local disks, especially as
they are much faster.
-----
Uwe Schindler
H.-H.-Meier-Allee 63, D-28213 Bremen
http://www.thetaphi.de
eMail: uwe@thetaphi.de
> -----Original Message-----
> From: nishesh.gupta@emc.com [mailto:nishesh.gupta@emc.com]
> Sent: Monday, November 14, 2011 10:37 PM
> To: java-user@lucene.apache.org
> Subject: Index Corruption with Lucene 2.9.3
>
> We are seeing Index corruption very often with version 2.9.3. Our indexing
> process is on Linux ( centos 5 ). Index is created on a mounted drive
which is a
> shared drive from Windows 2008 server running in a VM. We generally see
> index corruption in merge or optimize after indexing runs continuously for
6-7
> hrs with index size reaching around 7-8GB. To reproduce the corruptions
> sooner, I have placed the merge ( maybemerge ) call immediately after
> addIndex is called. We have a final index which is in the mounted drive,
we
> always add documents to an local intermediate index and then call add
index
> and merge to the final index.
>
> The exception that I get -
>
> 2011-11-11 15:19:16,929 [MC:10.10.176.148-1321045422606-204
> FS:emag_393219_0] ERROR indexer - MergeWithFiler: MC: 393219, shard 0,
> guid 10.10.176.148-1321045422606-204: Error in
> addIndex()/kazMaybeMerge():
> /sideline/fs_393219/cas/search/index_0/primary, java.io.IOException:
> background merge hit exception: _1t:c262436 _10.10.176.148-1321045422606-
> 204_0:cx4000 into _1u [optimize] [mergeDocStores] % STACK:
> org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2932)
> org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2867)
> org.apache.lucene.index.IndexWriter.optimize(IndexWriter.java:2837)
> org.apache.lucene.index.IndexWriter.addIndexes(IndexWriter.java:3652)
>
> com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerInde
> x(MergerContext.java:1004)
>
> com.kazeon.search.indexingengine.context.MergerContext.mergeWithFilerInde
> x(MergerContext.java:1094)
>
> com.kazeon.search.indexingengine.context.MergerContext.mergeWithFiler(Me
> rgerContext.java:1140)
>
> com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndex
> OptimizeAndCompressModifier.modifyStateAux(LocalIndexOptimizeAndCompr
> essModifier.java:375)
>
> com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndex
> OptimizeAndCompressModifier.mergeAllICs(LocalIndexOptimizeAndCompress
> Modifier.java:181)
>
> com.kazeon.search.indexingengine.statemachine.modifiers.merger.LocalIndex
> OptimizeAndCompressModifier.modifyState(LocalIndexOptimizeAndCompress
> Modifier.java:106)
> com.kazeon.util.scoreboard.WorkerThread.run(WorkerThread.java:31)
>
>
> CheckIndex command shows the following output -
>
> NOTE: testing will be more thorough if you run java with '-
> ea:org.apache.lucene...', so assertions are enabled
>
> Opening index @ .
>
> Segments file=segments_23 numSegments=1 version=FORMAT_DIAGNOSTICS
> [Lucene 2.9]
> 1 of 1: name=_1t docCount=262436
> compound=true
> hasProx=true
> numFiles=1
> size (MB)=937.835
> diagnostics = {optimize=true, mergeFactor=2,
os.version=2.6.18-92.1.18.el5,
> os=Linux, mergeDocStores=true, lucene.version=2.9.3-dev, source=merge,
> os.arch=i386, java.version=1.6.0_02, java.vendor=Sun Microsystems Inc.}
> no deletions
> test: open reader.........OK
> test: fields..............OK [79 fields]
> test: field norms.........OK [79 fields]
> test: terms, freq, prox...ERROR [term fulltext:creativecommons: doc
262603
> >= maxDoc 262436]
> java.lang.RuntimeException: term fulltext:creativecommons: doc 262603 >=
> maxDoc 262436
> at
org.apache.lucene.index.CheckIndex.testTermIndex(CheckIndex.java:646)
> at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:530)
> at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
> test: stored fields.......OK [524872 total field count; avg 2 fields
per doc]
> test: term vectors........OK [0 total vector count; avg 0 term/freq
vector fields
> per doc] FAILED
> WARNING: fixIndex() would remove reference to this segment; full
> exception:
> java.lang.RuntimeException: Term Index test failed
> at org.apache.lucene.index.CheckIndex.checkIndex(CheckIndex.java:543)
> at org.apache.lucene.index.CheckIndex.main(CheckIndex.java:903)
>
> WARNING: 1 broken segments (containing 262436 documents) detected
> WARNING: would write new segments file, and 262436 documents would be
> lost, if -fix were specified
>
>
>
> Lucene Indexwriter infostream around the corrupt segment _1t shows -
>
> 9620 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> setInfoStream: dir=org.apache.lucene.store.S
> impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary
> autoCommit=true mergePolicy=org.
> apache.lucene.index.LogByteSizeMergePolicy@2ac02f<mailto:apache.lucene.in
> dex.LogByteSizeMergePolicy@2ac02f>
> mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> heduler@af7be8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> maxBuffereDeleteTerms=-1 maxFieldLength=10000 index =_1s:c261077
> 9621 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> setMaxBufferedDocs 10000
> 9622 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush at addIndexes
> 9623 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9624 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9625 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077
> 9626 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> start transaction
> 9627 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush at startTransaction
> 9628 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9629 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9630 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077
> 9631 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> 361_0:cx1359**
> 9632 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9633 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9634 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> 361_0:cx1359**
> 9635 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: add
> merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> 361_0:cx1359 [optimize] [total 1 pending]
> 9636 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9637 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1s:c261077 _10.10.176.148-132
1053007682-361_0:cx1359**
> 9638 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> 9639 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: launch new thread [Lucene Merge Thr ead #0]
> 9640 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9641 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: start
> 9642 IW 130 [Lucene Merge Thread #0]: now merge
> 9643 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into
> _1t [optimize] [mergeDocStores]
> 9644
> merge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb<mailto:m
> erge=org.apache.lucene.index.MergePolicy$OneMerge@116eedb>
> 9645 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> 9646 IW 130 [Lucene Merge Thread #0]: merging _1s:c261077 _10.10.176.148-
> 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> 9647 IW 130 [Lucene Merge Thread #0]: merge: total 262436 docs
> 9648 IW 130 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> 361_0:cx1359**
> 9649 IW 130 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> [mergeDocStores]
> 9650 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9651 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9652 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9653 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> 9654 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> 9655 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> 9656 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> 9657 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> 9658 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> 9659 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> 9660 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> 9661 IW 130 [Lucene Merge Thread #0]: CMS: merge thread: done
> 9662 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> commit transaction
> 9663 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> 9664 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit(): start sizeInBytes=0
> 9665 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit index=_1t:c262436 changeCount=4
> 9666 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> sync _1t.cfs
> 9667 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> done all syncs
> 9668 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: pendingCommit != null
> 9669 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: wrote segments file "segments_1v"
> 9670 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> 9671 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> deleteCommits: now decRef commit "segments_1u"
> 9672 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete
> "_1s.cfs"
> 9673 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete
> "segments_1u"
> 9674 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: done
> 9675 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> LMP: findMerges: 1 segments
> 9676 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> LMP: level 8.242726 to 8.992726: 1 segment s
> 9677 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9678 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1t:c262436
> 9679 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9680 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> flush at close
> 9681 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9682 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9683 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9684 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9685 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1t:c262436
> 9686 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9687 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> call final commit()
> 9688 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit(): start sizeInBytes=0
> 9689 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> skip startCommit(): no changes pending
> 9690 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: pendingCommit == null; skip
> 9691 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: done
> 9692 IW 130 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> close: _1t:c262436
> 9693 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> setInfoStream deletionPolicy=org.apache.lucene.
> index.KeepOnlyLastCommitDeletionPolicy@28cdb8<mailto:index.KeepOnlyLast
> CommitDeletionPolicy@28cdb8>
> 9694 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> setInfoStream: dir=org.apache.lucene.store.S
> impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/second
> ary autoCommit=true mergePolicy=or
> g.apache.lucene.index.LogByteSizeMergePolicy@da05c8<mailto:g.apache.luce
> ne.index.LogByteSizeMergePolicy@da05c8>
> mergeScheduler=org.apache.lucene.index.ConcurrentMerge
> Scheduler@1b1c02b ramBufferSizeMB=16.0 maxBufferedDocs=-1
> maxBuffereDeleteTerms=-1 maxFieldLength=10000 in dex=_1s:c261077
> 9695 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> setMaxBufferedDocs 10000
> 9696 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush at addIndexes
> 9697 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9698 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9699 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077
> 9700 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> start transaction
> 9701 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush at startTransaction
> 9702 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9703 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9704 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077
> 9705 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> optimize: index now _1s:c261077 _10.10.176.1 48-1321053007682-
> 361_0:cx1359**
> 9706 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9707 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9708 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1s:c261077 _10.10.176. 148-1321053007682-
> 361_0:cx1359**
> 9709 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: add
> merge to pendingMerges: _1s:c261077 _10. 10.176.148-1321053007682-
> 361_0:cx1359 [optimize] [total 1 pending]
> 9710 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9711 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1s:c261077 _10.10.176.148-132
1053007682-361_0:cx1359**
> 9712 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: consider merge _1s:c261077 _10.10.176 .148-1321053007682-
> 361_0:cx1359 into _1t [optimize] [mergeDocStores]
> 9713 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: launch new thread [Lucene Merge Thr ead #0]
> 9714 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9715 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: start
> 9716 IW 131 [Lucene Merge Thread #0]: now merge
> 9717 merge=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359 into
> _1t [optimize] [mergeDocStores]
> 9718
> merge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f<mailto:me
> rge=org.apache.lucene.index.MergePolicy$OneMerge@15aa40f>
> 9719 index=_1s:c261077 _10.10.176.148-1321053007682-361_0:cx1359**
> 9720 IW 131 [Lucene Merge Thread #0]: merging _1s:c261077 _10.10.176.148-
> 1321053007682-361_0:cx1359 into _1t [o ptimize] [mergeDocStores]
> 9721 IW 131 [Lucene Merge Thread #0]: merge: total 262436 docs
> 9722 IW 131 [Lucene Merge Thread #0]: commitMerge: _1s:c261077
> _10.10.176.148-1321053007682-361_0:cx1359 into _ 1t [optimize]
> [mergeDocStores] index=_1s:c261077 _10.10.176.148-1321053007682-
> 361_0:cx1359**
> 9723 IW 131 [Lucene Merge Thread #0]: commitMergeDeletes _1s:c261077
> _10.10.176.148-1321053007682-361_0:cx1359 into _1t [optimize]
> [mergeDocStores]
> 9724 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9725 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9726 IFD [Lucene Merge Thread #0]: now checkpoint "segments_1u" [1
> segments ; isCommit = false]
> 9727 IFD [Lucene Merge Thread #0]: delete "_1t.fnm"
> 9728 IFD [Lucene Merge Thread #0]: delete "_1t.frq"
> 9729 IFD [Lucene Merge Thread #0]: delete "_1t.prx"
> 9730 IFD [Lucene Merge Thread #0]: delete "_1t.tis"
> 9731 IFD [Lucene Merge Thread #0]: delete "_1t.tii"
> 9732 IFD [Lucene Merge Thread #0]: delete "_1t.nrm"
> 9733 IFD [Lucene Merge Thread #0]: delete "_1t.fdx"
> 9734 IFD [Lucene Merge Thread #0]: delete "_1t.fdt"
> 9735 IW 131 [Lucene Merge Thread #0]: CMS: merge thread: done
> 9736 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> commit transaction
> 9737 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> checkpoint "segments_1u" [1 segments ; isCo mmit = false]
> 9738 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit(): start sizeInBytes=0
> 9739 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit index=_1t:c262436 changeCount=4
> 9740 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> sync _1t.cfs
> 9741 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> done all syncs
> 9742 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: pendingCommit != null
> 9743 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: wrote segments file "segments_1v"
> 9744 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> checkpoint "segments_1v" [1 segments ; isCo mmit = true]
> 9745 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> deleteCommits: now decRef commit "segments_1u"
> 9746 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete
> "_1s.cfs"
> 9747 IFD [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: delete
> "segments_1u"
> 9748 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: done
> 9749 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> LMP: findMerges: 1 segments
> 9750 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> LMP: level 7.2867203 to 8.03672: 1 segment s
> 9751 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9752 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1t:c262436
> 9753 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9754 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> flush at close
> 9755 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9756 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9757 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9758 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: now merge
> 9759 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: index: _1t:c262436
> 9760 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9761 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: now
> call final commit()
> 9762 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> startCommit(): start sizeInBytes=0
> 9763 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> skip startCommit(): no changes pending
> 9764 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: pendingCommit == null; skip
> 9765 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]:
> commit: done
> 9766 IW 131 [MC:10.10.176.148-1321053007682-361 FS:emag_393219_0]: at
> close: _1t:c262436
> 9767 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setInfoStream deletionPolicy=org.apache.lucene.
> index.KeepOnlyLastCommitDeletionPolicy@8506f9<mailto:index.KeepOnlyLast
> CommitDeletionPolicy@8506f9>
> 9768 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setInfoStream: dir=org.apache.lucene.store.S
> impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary
> autoCommit=true mergePolicy=org.
> apache.lucene.index.LogByteSizeMergePolicy@18d0653<mailto:apache.lucene.
> index.LogByteSizeMergePolicy@18d0653>
> mergeScheduler=org.apache.lucene.index.ConcurrentMergeS
> cheduler@19a5bf2 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> maxBuffereDeleteTerms=-1 maxFieldLength=10000 ind ex=_1t:c262436
> 9769 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setMaxBufferedDocs 10000
> 9770 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush at addIndexes
> 9771 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9772 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9773 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9774 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> start transaction
> 9775 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush at startTransaction
> 9776 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9777 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9778 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9779 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> optimize: index now _1t:c262436 _10.10.176.1 48-1321045422606-
> 204_0:cx4000**
> 9780 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9781 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9782 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> index before flush _1t:c262436 _10.10.176. 148-1321045422606-
> 204_0:cx4000**
> 9783 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: add
> merge to pendingMerges: _1t:c262436 _10. 10.176.148-1321045422606-
> 204_0:cx4000 [optimize] [total 1 pending]
> 9784 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: now merge
> 9785 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: index: _1t:c262436 _10.10.176.148-132
1045422606-204_0:cx4000**
> 9786 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: consider merge _1t:c262436 _10.10.176 .148-1321045422606-
> 204_0:cx4000 into _1u [optimize] [mergeDocStores]
> 9787 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: launch new thread [Lucene Merge Thr ead #0]
> 9788 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9789 IW 132 [Lucene Merge Thread #0]: CMS: merge thread: start
> 9790 IW 132 [Lucene Merge Thread #0]: now merge
> 9791 merge=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000 into
> _1u [optimize] [mergeDocStores]
> 9792
> merge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25<mailto:mer
> ge=org.apache.lucene.index.MergePolicy$OneMerge@3b0c25>
> 9793 index=_1t:c262436 _10.10.176.148-1321045422606-204_0:cx4000**
> 9794 IW 132 [Lucene Merge Thread #0]: merging _1t:c262436 _10.10.176.148-
> 1321045422606-204_0:cx4000 into _1u [o ptimize] [mergeDocStores]
> 9795 IW 132 [Lucene Merge Thread #0]: merge: total 266436 docs
> 9796 IW 132 [Lucene Merge Thread #0]: handleMergeException:
> merge=_1t:c262436 _10.10.176.148-1321045422606-204_ 0:cx4000 into
> _1u [optimize] [mergeDocStores]
> exc=org.apache.lucene.index.CorruptIndexException: docs out of order
> (262439 <= 2096427 )
> 9797 IW 132 [Lucene Merge Thread #0]: hit exception during merge
> 9798 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.fdt"
> 9799 IFD [Lucene Merge Thread #0]: delete "_1u.fdt"
> 9800 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.fdx"
> 9801 IFD [Lucene Merge Thread #0]: delete "_1u.fdx"
> 9802 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.fnm"
> 9803 IFD [Lucene Merge Thread #0]: delete "_1u.fnm"
> 9804 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.frq"
> 9805 IFD [Lucene Merge Thread #0]: delete "_1u.frq"
> 9806 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.prx"
> 9807 IFD [Lucene Merge Thread #0]: delete "_1u.prx"
> 9808 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.tii"
> 9809 IFD [Lucene Merge Thread #0]: delete "_1u.tii"
> 9810 IFD [Lucene Merge Thread #0]: refresh [prefix=_1u]: removing newly
> created unreferenced file "_1u.tis"
> 9811 IFD [Lucene Merge Thread #0]: delete "_1u.tis"
> 9812 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> rollback transaction
> 9813 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: all
> running merges have aborted
> 9814 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> checkpoint "segments_1v" [1 segments ; isCo mmit = false]
> 9815 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> flush at close
> 9816 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9817 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9818 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9819 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: now merge
> 9820 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: index: _1t:c262436
> 9821 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> CMS: no more merges pending; now return
> 9822 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> call final commit()
> 9823 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> startCommit(): start sizeInBytes=0
> 9824 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> startCommit index=_1t:c262436 changeCount=1
> 9825 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> done all syncs
> 9826 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> commit: pendingCommit != null
> 9827 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> commit: wrote segments file "segments_1w"
> 9828 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> checkpoint "segments_1w" [1 segments ; isCo mmit = true]
> 9829 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> deleteCommits: now decRef commit "segments_1v"
> 9830 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: delete
> "segments_1v"
> 9831 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> commit: done
> 9832 IW 132 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: at
> close: _1t:c262436
> 9833 IFD [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setInfoStream deletionPolicy=org.apache.lucene.
> index.KeepOnlyLastCommitDeletionPolicy@1ec4b8e<mailto:index.KeepOnlyLas
> tCommitDeletionPolicy@1ec4b8e>
> 9834 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setInfoStream: dir=org.apache.lucene.store.S
> impleFSDirectory@/cas/fs_589826/sideline/fs_393219/search/index_0/primary
> autoCommit=true mergePolicy=org.
> apache.lucene.index.LogByteSizeMergePolicy@546a0e<mailto:apache.lucene.i
> ndex.LogByteSizeMergePolicy@546a0e>
> mergeScheduler=org.apache.lucene.index.ConcurrentMergeSc
> heduler@1fef5b8 ramBufferSizeMB=16.0 maxBufferedDocs=-1
> maxBuffereDeleteTerms=-1 maxFieldLength=10000 inde x=_1t:c262436
> 9835 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> setMaxBufferedDocs 10000
> 9836 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush at addIndexes
> 9837 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: now pause all indexing threads
> 9838 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> flush: segment=null docStoreSegment=null d ocStoreOffset=0
> flushDocs=false flushDeletes=true flushDocStores=false numDocs=0
> numBufDelTerms=0
> 9839 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]:
> index before flush _1t:c262436
> 9840 IW 133 [MC:10.10.176.148-1321045422606-204 FS:emag_393219_0]: now
> start transaction
---------------------------------------------------------------------
To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
For additional commands, e-mail: java-user-help@lucene.apache.org