lucene-java-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Frank Geary <fge...@acquiremedia.com>
Subject Re: Index corruption using Lucene 2.4.1 - thread safety issue?
Date Fri, 22 Jan 2010 17:02:20 GMT

Mike,

Below are the portions of the merge log files related to the setInfoStream()
calls during the time our exception happens.  The ..._1... log file is from
one RAMDir index and the ..._0... log file is from the other RAMDir index. 
The time period when our Array index out of bounds exception happens is
2009-12-27 19:59:51,244 (when the IndexReader.reopen() is about to be
called) to 2009-12-27 19:59:51,259 (when the exception is thrown from the
MultiIndexSearch.search() call).  As you can see from the log files below,
our "_1" RAMDir index is the only one being used during the time the
exception is thrown - not new information to me.  Also a merge has finished
at 2009-12-27 19:59:50,561 and thus it appears that nothing at all is
happening (with respect to merges or commits) in either RAMDir index at the
time the problem occurs.  But one thing that is interesting to me - perhaps
you can clarify - is there is a very short commit at the very top of the
"_1" log file.  Why is that commit different from the commit right below it? 
What does "DW: apply 1 buffered deleted terms and 0 deleted docIDs" mean? 
What does "commit: pendingCommit == null; skip" mean?  Are there different
kinds of commit?

Here's the log file info:


indexmergesched_1_20091227161034212.log


[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]: commit: start
[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]: commit: now prepare
[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]: prepareCommit: flush
[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]:   flush: segment=null
docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true 

flushDocStores=false numDocs=0 numBufDelTerms=1
[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]:   index before flush
_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1 _yy:C1 

_yz:C1 _z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1
[2009-12-27 19:59:50,534Z]: IW 48 [pool-2-thread-1]: DW: apply 1 buffered
deleted terms and 0 deleted docIDs and 0 deleted queries on 15 segments.
[2009-12-27 19:59:50,536Z]: IW 48 [pool-2-thread-1]: startCommit(): start
sizeInBytes=0
[2009-12-27 19:59:50,536Z]: IW 48 [pool-2-thread-1]:   skip startCommit():
no changes pending
[2009-12-27 19:59:50,536Z]: IW 48 [pool-2-thread-1]: commit: pendingCommit
== null; skip
[2009-12-27 19:59:50,536Z]: IW 48 [pool-2-thread-1]: commit: done
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]: commit: start
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]: commit: now prepare
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]: prepareCommit: flush
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]:   flush: segment=_z6
docStoreSegment=_z6 docStoreOffset=0 flushDocs=true flushDeletes=true 

flushDocStores=true numDocs=1 numBufDelTerms=0
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]:   index before flush
_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1 _yy:C1 

_yz:C1 _z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]: DW: flush postings as
segment _z6 numDocs=1
[2009-12-27 19:59:50,543Z]: IW 48 [pool-2-thread-1]: DW: closeDocStore: 2
files to flush to segment _z6 numDocs=1
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: DW:   oldRAMSize=59392
newFlushedSize=6213 docs/MB=168.771 new/old=10.461%
[2009-12-27 19:59:50,544Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xv" [16 segments ; isCommit = false]
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: LMP: findMerges: 16
segments
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: LMP:   level 6.2247195
to 6.2465463: 5 segments
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: LMP:   level -1.0 to
5.8754334: 11 segments
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: LMP:     5 to 15: add
this merge
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: alwaysMerge=true
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: CMS: now merge
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: CMS:   index: _6o:C206
_dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1 _yy:C1 _yz:C1 

_z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: CMS:   no more merges
pending; now return
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: startCommit(): start
sizeInBytes=0
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: startCommit
index=_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1
_yy:C1 _yz:C1 

_z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1 changeCount=2598
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.fnm
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.frq
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.prx
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.tis
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.tii
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.nrm
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.fdx
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: now sync _z6.fdt
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: done all syncs
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: commit: pendingCommit
!= null
[2009-12-27 19:59:50,544Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xw" [16 segments ; isCommit = true]
[2009-12-27 19:59:50,544Z]: IFD [pool-2-thread-1]: deleteCommits: now decRef
commit "segments_xv"
[2009-12-27 19:59:50,544Z]: IFD [pool-2-thread-1]: delete "segments_xv"
[2009-12-27 19:59:50,544Z]: IW 48 [pool-2-thread-1]: commit: done
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]: commit: start
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]: commit: now prepare
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]: prepareCommit: flush
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]:   flush: segment=_z7
docStoreSegment=_z7 docStoreOffset=0 flushDocs=true flushDeletes=true 

flushDocStores=true numDocs=1 numBufDelTerms=0
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]:   index before flush
_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1 _yy:C1 

_yz:C1 _z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]: DW: flush postings as
segment _z7 numDocs=1
[2009-12-27 19:59:50,556Z]: IW 48 [pool-2-thread-1]: DW: closeDocStore: 2
files to flush to segment _z7 numDocs=1
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: DW:   oldRAMSize=59392
newFlushedSize=6156 docs/MB=170.334 new/old=10.365%
[2009-12-27 19:59:50,557Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xw" [17 segments ; isCommit = false]
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: LMP: findMerges: 17
segments
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: LMP:   level 6.2247195
to 6.2465463: 5 segments
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: LMP:   level -1.0 to
5.8754334: 12 segments
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: LMP:     5 to 15: add
this merge
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: alwaysMerge=true
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: CMS: now merge
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: CMS:   index: _6o:C206
_dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1 _yy:C1 _yz:C1 

_z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1 _z7:C1
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: CMS:   no more merges
pending; now return
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: startCommit(): start
sizeInBytes=0
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: startCommit
index=_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1
_yy:C1 _yz:C1 

_z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1 _z7:C1 changeCount=2600
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.fnm
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.frq
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.prx
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.tis
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.tii
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.nrm
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.fdx
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: now sync _z7.fdt
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: done all syncs
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: commit: pendingCommit
!= null
[2009-12-27 19:59:50,557Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xx" [17 segments ; isCommit = true]
[2009-12-27 19:59:50,557Z]: IFD [pool-2-thread-1]: deleteCommits: now decRef
commit "segments_xw"
[2009-12-27 19:59:50,557Z]: IFD [pool-2-thread-1]: delete "segments_xw"
[2009-12-27 19:59:50,557Z]: IW 48 [pool-2-thread-1]: commit: done
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]: commitMerge:
_yv:C71 _yw:C1 _yx:C1 _yy:C1 _yz:C1 _z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 into 

_z5 index=_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _yv:C71 _yw:C1 _yx:C1
_yy:C1 _yz:C1 _z0:C1 _z1:C1 _z2:C1 _z3:C1 _z4:C1 _z6:C1 _z7:C1
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]:
commitMergeDeletes _yv:C71 _yw:C1 _yx:C1 _yy:C1 _yz:C1 _z0:C1 _z1:C1 _z2:C1
_z3:C1 _z4:C1 

into _z5
[2009-12-27 19:59:50,561Z]: IFD [Lucene Merge Thread #125]: now checkpoint
"segments_xx" [8 segments ; isCommit = false]
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]: LMP:
findMerges: 8 segments
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]: LMP:   level
6.2247195 to 6.2465463: 5 segments
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]: LMP:   level
-1.0 to 5.910075: 3 segments
[2009-12-27 19:59:50,561Z]: IW 48 [Lucene Merge Thread #125]: CMS:   merge
thread: done
[2009-12-27 19:59:50,561Z]: IW 48 [Thread-108842]:
AMConcurrentMergeScheduler: merge is done
[2009-12-27 20:00:05,494Z]: IW 48 [pool-2-thread-1]: commit: start
[2009-12-27 20:00:05,494Z]: IW 48 [pool-2-thread-1]: commit: now prepare
[2009-12-27 20:00:05,494Z]: IW 48 [pool-2-thread-1]: prepareCommit: flush
[2009-12-27 20:00:05,494Z]: IW 48 [pool-2-thread-1]:   flush: segment=null
docStoreSegment=null docStoreOffset=0 flushDocs=false flushDeletes=true 

flushDocStores=false numDocs=0 numBufDelTerms=1
[2009-12-27 20:00:05,494Z]: IW 48 [pool-2-thread-1]:   index before flush
_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _z5:C80 _z6:C1 _z7:C1
[2009-12-27 20:00:05,495Z]: IW 48 [pool-2-thread-1]: DW: apply 1 buffered
deleted terms and 0 deleted docIDs and 0 deleted queries on 8 segments.
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xx" [8 segments ; isCommit = false]
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: startCommit(): start
sizeInBytes=0
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: startCommit
index=_6o:C206 _dd:C207 _iy:C181 _q7:C225 _wm:C203 _z5:C80 _z6:C1 _z7:C1 

changeCount=2602
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.fnm
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.frq
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.prx
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.tis
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.tii
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.nrm
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.fdx
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5.fdt
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: now sync _z5_1.del
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: done all syncs
[2009-12-27 20:00:05,496Z]: IW 48 [pool-2-thread-1]: commit: pendingCommit
!= null
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_xy" [8 segments ; isCommit = true]
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: deleteCommits: now decRef
commit "segments_xx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "segments_xx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.fnm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.frq"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.prx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.tis"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.tii"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.nrm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.fdx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yv.fdt"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.fnm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.frq"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.prx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.tis"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.tii"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.nrm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.fdx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yw.fdt"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.fnm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.frq"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.prx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.tis"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.tii"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.nrm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.fdx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yx.fdt"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.fnm"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.frq"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.prx"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.tis"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.tii"
[2009-12-27 20:00:05,496Z]: IFD [pool-2-thread-1]: delete "_yy.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yy.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yy.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_yz.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z0.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z1.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z2.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z3.fdt"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.fnm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.frq"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.prx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.tis"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.tii"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.nrm"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.fdx"
[2009-12-27 20:00:05,497Z]: IFD [pool-2-thread-1]: delete "_z4.fdt"
[2009-12-27 20:00:05,497Z]: IW 48 [pool-2-thread-1]: commit: done

indexmergesched_0_20091227193729876.log

[2009-12-27 19:37:29,876Z]: IFD [ArchiveIndexSearcherFactoryCreator]:
setInfoStream
deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@624e2c55
[2009-12-27 19:37:29,876Z]: IW 49 [ArchiveIndexSearcherFactoryCreator]:
setInfoStream: dir=org.apache.lucene.store.RAMDirectory@1bc74f37
autoCommit=false
mergePolicy=org.apache.lucene.index.LogByteSizeMergePolicy@7a40b2de
mergeScheduler=org.apache.lucene.index.AMConcurrentMergeScheduler@2d9f4b86
ramBufferSizeMB=16.0 maxBufferedDocs=60 maxBuffereDeleteTerms=-1
maxFieldLength=100000 index=
[2009-12-27 23:07:17,197Z]: IW 49 [pool-2-thread-1]: commit: start
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]: commit: now prepare
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]: prepareCommit: flush
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]:   flush: segment=_0
docStoreSegment=_0 docStoreOffset=0 flushDocs=true flushDeletes=true
flushDocStores=true numDocs=1 numBufDelTerms=0
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]:   index before flush
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]: DW: flush postings as
segment _0 numDocs=1
[2009-12-27 23:07:17,200Z]: IW 49 [pool-2-thread-1]: DW: closeDocStore: 2
files to flush to segment _0 numDocs=1
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: DW:   oldRAMSize=151552
newFlushedSize=11654 docs/MB=89.976 new/old=7.69%
[2009-12-27 23:07:17,201Z]: IFD [pool-2-thread-1]: now checkpoint
"segments_1" [1 segments ; isCommit = false]
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: LMP: findMerges: 1
segments
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: LMP:   level -1.0 to
4.1824718: 1 segments
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: alwaysMerge=true
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: CMS: now merge
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: CMS:   index: _0:C1
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: CMS:   no more merges
pending; now return
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: startCommit(): start
sizeInBytes=0
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: startCommit index=_0:C1
changeCount=2
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.fnm
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.frq
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.prx
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.tis
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.tii
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.nrm
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.fdx
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: now sync _0.fdt
[2009-12-27 23:07:17,201Z]: IW 49 [pool-2-thread-1]: done all syncs

Frank


Michael McCandless-2 wrote:
> 
> On Thu, Jan 21, 2010 at 4:46 PM, Frank Geary <fgeary@acquiremedia.com>
> wrote:
> 
>> Nope.  When it's time to inactivate a RAMDir indexWriter, I get that
>> directory,  close that writer, then clear out the directory.  Then after
>> clearing out the directory, I create a new IW passing in the directory
>> that
>> was used previously.  No, I do not override the LockFactory - not
>> familiar
>> with it.
> 
> Hmm, curious.
> 
>> Hmm...for what it's worth we are using ConcurrentMergeScheduler.
>> We do actaully have setInfoStream turned on for all our indexers.  I'll
>> have
>> to hunt down one of our logs that corresponds to one of the Exceptions
>> though.  Thanks for that.
> 
> That could be helpful... eg it'd let us confirm every open IW is
> closed before a new one is opened, on the same IW (assuming we get the
> full output from all opened IWs).
> 
>> We delete the files explicitly, because what we found was that under high
>> index loads (i.e. rapid rolling of RAMDir indexWriters) leaving the
>> RAMDir
>> around lead to garbage collection issues as old RAMDirs accumulated
>> waiting
>> for garbage collection to take place.  It turned out that deleting the
>> files
>> explicitly avoided those garbage collection problems.
> 
> That's very odd -- RAMDir should be "easy" to GC once it's closed.  It
> (and RAMFile) have no finalizers.
> 
> Were you calling RAMDir.close()?  That clears its fileMap, which will
> make all RAM consumed GCable.
> 
> The fact that you hit GC issues makes me suspect something, somewhere
> is still hanging on to the RAMDir (ie, the IW isn't always being
> closed).
> 
> If you go back to using a new RAMDir instance per IW, does the problem go
> away?
> 
> Mike
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: java-user-unsubscribe@lucene.apache.org
> For additional commands, e-mail: java-user-help@lucene.apache.org
> 
> 
> 

-- 
View this message in context: http://old.nabble.com/Index-corruption-using-Lucene-2.4.1---thread-safety-issue--tp27115515p27276550.html
Sent from the Lucene - Java Users mailing list archive at Nabble.com.


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


Mime
View raw message