Return-Path: X-Original-To: apmail-lucene-java-user-archive@www.apache.org Delivered-To: apmail-lucene-java-user-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id D6E8370B2 for ; Tue, 15 Nov 2011 10:47:45 +0000 (UTC) Received: (qmail 86079 invoked by uid 500); 15 Nov 2011 10:47:43 -0000 Delivered-To: apmail-lucene-java-user-archive@lucene.apache.org Received: (qmail 85973 invoked by uid 500); 15 Nov 2011 10:47:42 -0000 Mailing-List: contact java-user-help@lucene.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: java-user@lucene.apache.org Delivered-To: mailing list java-user@lucene.apache.org Received: (qmail 85965 invoked by uid 99); 15 Nov 2011 10:47:42 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 15 Nov 2011 10:47:42 +0000 X-ASF-Spam-Status: No, hits=-0.0 required=5.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of uwe@thetaphi.de designates 188.138.97.18 as permitted sender) Received: from [188.138.97.18] (HELO mail.sd-datasolutions.de) (188.138.97.18) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 15 Nov 2011 10:47:37 +0000 Received: from VEGA (gate2.marum.de [134.102.237.2]) by mail.sd-datasolutions.de (Postfix) with ESMTPSA id F02C714AA00A for ; Tue, 15 Nov 2011 10:47:14 +0000 (UTC) From: "Uwe Schindler" To: References: <010401cca31d$676cbba0$364632e0$@thetaphi.de> <010801cca31e$23376100$69a62300$@thetaphi.de> In-Reply-To: Subject: RE: Index Corruption with Lucene 2.9.3 Date: Tue, 15 Nov 2011 11:47:19 +0100 Message-ID: <003c01cca383$f2e7e9f0$d8b7bdd0$@thetaphi.de> MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit X-Mailer: Microsoft Outlook 14.0 thread-index: AQG/bc8VmbWe+mz7bShHK6412ZfhggKSWNErAn3v8ccBJdnetpWWd7Tg Content-Language: 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 > > 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 > > 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 > > 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 > > 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 > > 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 > > 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 > > 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 > > 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 > > 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 > > 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