lucene-general mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Nishesh <nishesh.gu...@emc.com>
Subject Index Corruption in Lucene 2.9.3
Date Mon, 14 Nov 2011 19:47:09 GMT
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
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
 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
 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
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
 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
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
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
 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
 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
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


--
View this message in context: http://lucene.472066.n3.nabble.com/Index-Corruption-in-Lucene-2-9-3-tp3507788p3507788.html
Sent from the Lucene - General mailing list archive at Nabble.com.

Mime
View raw message