OK, this seems to be a test bug: somehow, the main thread is removing the entire index directory from the filesystem, before another thread calls IW.close.
I can see the test opens 5 IW instances, and then things run fine, and then the 5 IWs are closed in sequence in a thread, but in the main thread is returning (randomized testing prints "OK 20.1s | TestDistribDocBasedVersion.testDistribSearch") before the last 2 IWs are closed. So somewhere in the main thread, something is concurrently removing the index directory before the last 2 IWs are closed. I tried passing -Dtests.leaveTemporary=true and the test still fails, so I don't think it's test-framework that's removing the index dir; I think it's something somewhere in Solr's test infrastructure? Probably there is just a missing call somewhere to cleanly shutdown all cores before cleaning up? Mike McCandless http://blog.mikemccandless.com On Fri, Jan 10, 2014 at 3:56 PM, Michael McCandless <[email protected]> wrote: > Repros for me too ... I'll dig. > > Mike McCandless > > http://blog.mikemccandless.com > > > On Fri, Jan 10, 2014 at 11:55 AM, Chris Hostetter > <[email protected]> wrote: >> >> FWIW: this seed reproduce for me on 4x... >> >> ant test -Dtestcase=TestDistribDocBasedVersion >> -Dtests.seed=791402573DC76F3C -Dtests.multiplier=3 -Dtests.slow=true >> -Dtests.locale=ar_IQ -Dtests.timezone=Antarctica/Rothera >> -Dtests.file.encoding=US-ASCII >> >> The test isn't doing anything odd with merges, but it does use the >> ranomized index configs (solrconfig.snippet.randomindexconfig.xml) and i >> notice this in the logs.... >> >> [junit4] 2> 27628 T91 oasu.DirectUpdateHandler2.close closing >> DirectUpdateHandler2{commits=2,autocommits=0,soft >> autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=8,adds=8,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=22,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=2} >> [junit4] 2> 27628 T91 oasu.SolrCoreState.decrefSolrCoreState Closing >> SolrCoreState >> [junit4] 2> 27628 T91 oasu.DefaultSolrCoreState.closeIndexWriter >> SolrCoreState ref count has reached 0 - closing IndexWriter >> [junit4] 2> 27629 T91 oasu.DefaultSolrCoreState.closeIndexWriter >> closing IndexWriter with IndexWriterCloser >> [junit4] 2> 27631 T91 C12 P38577 oasu.DirectUpdateHandler2.closeWriter >> ERROR Error in final commit java.io.FileNotFoundException: _0.cfe >> [junit4] 2> at >> org.apache.lucene.store.FSDirectory.fileLength(FSDirectory.java:267) >> [junit4] 2> at >> org.apache.lucene.store.NRTCachingDirectory.fileLength(NRTCachingDirectory.java:178) >> [junit4] 2> at >> org.apache.lucene.index.SegmentCommitInfo.sizeInBytes(SegmentCommitInfo.java:141) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.registerMerge(IndexWriter.java:3785) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.updatePendingMerges(IndexWriter.java:1971) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.maybeMerge(IndexWriter.java:1935) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2874) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:2979) >> [junit4] 2> at >> org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:2949) >> [junit4] 2> at >> org.apache.solr.update.DirectUpdateHandler2.closeWriter(DirectUpdateHandler2.java:746) >> >> Followd by the assertion failure mentioned bellow... >> >> >> >> : This is a test i'm familiar with, but the failure is aparently an >> : assertion in IndexWriter._mergeInit that should probably get some more >> : eyeballs on it... >> : >> : (Note: this is apparently 4x as of r1556643) >> : >> : : Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8922/ >> : : Java: 64bit/jdk1.7.0_60-ea-b02 -XX:-UseCompressedOops -XX:+UseG1GC >> : >> : : >> junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion >> : >> : ... >> : >> : : Stack Trace: >> : : com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an >> uncaught exception in thread: Thread[id=4981, name=Lucene Merge Thread #0, >> state=RUNNABLE, group=TGRP-TestDistribDocBasedVersion] >> : : Caused by: org.apache.lucene.index.MergePolicy$MergeException: >> java.lang.AssertionError >> : : at __randomizedtesting.SeedInfo.seed([791402573DC76F3C]:0) >> : : at >> org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:545) >> : : at >> org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:518) >> : : Caused by: java.lang.AssertionError >> : : at >> org.apache.lucene.index.IndexWriter._mergeInit(IndexWriter.java:3807) >> : : at >> org.apache.lucene.index.IndexWriter.mergeInit(IndexWriter.java:3791) >> : : at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3644) >> : : at >> org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:405) >> : : at >> org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:482) >> : >> : If i'm reading this right, as of r1556643 the assertion that tripped was >> : "assert merge.registerDone;" ... >> : >> : >> https://svn.apache.org/viewvc/lucene/dev/branches/branch_4x/lucene/core/src/java/org/apache/lucene/index/IndexWriter.java?revision=r1556643&view=markup#l3807 >> : >> : Any idea what could cause that assertion to fail? >> : >> : >> : -Hoss >> : http://www.lucidworks.com/ >> : >> >> -Hoss >> http://www.lucidworks.com/ >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
