You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by je...@sd-datasolutions.de on 2012/06/10 06:14:49 UTC
[JENKINS] Lucene-Solr-trunk-Linux-Java7-64 - Build # 227 - Failure!
Build: http://jenkins.sd-datasolutions.de/job/Lucene-Solr-trunk-Linux-Java7-64/227/
1 tests failed.
REGRESSION: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #0,6,]
Stack Trace:
java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #0,6,]
at com.carrotsearch.randomizedtesting.RunnerThreadGroup.processUncaught(RunnerThreadGroup.java:96)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:857)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$700(RandomizedRunner.java:132)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3$1.run(RandomizedRunner.java:669)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:695)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:734)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:745)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleReportUncaughtExceptions$1.evaluate(TestRuleReportUncaughtExceptions.java:68)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:38)
at org.apache.lucene.util.TestRuleIcuHack$1.evaluate(TestRuleIcuHack.java:51)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleNoInstanceHooksOverrides$1.evaluate(TestRuleNoInstanceHooksOverrides.java:53)
at org.apache.lucene.util.TestRuleNoStaticHooksShadowing$1.evaluate(TestRuleNoStaticHooksShadowing.java:52)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:36)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:56)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSuite(RandomizedRunner.java:605)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$400(RandomizedRunner.java:132)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2.run(RandomizedRunner.java:551)
Caused by: org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.store.AlreadyClosedException: this Directory is closed
at __randomizedtesting.SeedInfo.seed([8E33604CEEF4957D]:0)
at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:507)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:480)
Caused by: org.apache.lucene.store.AlreadyClosedException: this Directory is closed
at org.apache.lucene.store.Directory.ensureOpen(Directory.java:244)
at org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:241)
at org.apache.lucene.index.IndexFileDeleter.refresh(IndexFileDeleter.java:321)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3127)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:382)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:451)
Build Log:
[...truncated 35649 lines...]
[junit4] 2> 29704 T1211 C32 P42667 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29705 T1220 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e186ba1 main{StandardDirectoryReader(segments_2:1225 _6h(5.0):C1024/10 _cp(5.0):C1031/33 _fv(5.0):C525/20 _fu(5.0):C10 _fw(5.0):C10 _fx(5.0):C10 _fy(5.0):C10 _fz(5.0):C3)}
[junit4] 2> 29706 T1211 C32 P42667 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 128
[junit4] 2> 29708 T1224 C33 P56580 oasu.DirectUpdateHandler2.commit start commit{flags=0,version=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4] 2> 29794 T1224 C33 P56580 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux-Java7-64/checkout/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-1339301365453/jetty1/index,segFN=segments_3,generation=3,filenames=[_ey_Lucene40_0.tim, _f2_nrm.cfs, _f0.fnm, _f0_nrm.cfe, _ey_Lucene40_0.tip, _ez.fdx, _ez_nrm.cfs, _cq_1.del, _f0_Lucene40_0.prx, _f4.fdt, _ey_Lucene40_0.frq, _ez_Lucene40_0.tim, _ez_Lucene40_0.tip, _cq.si, _f0_nrm.cfs, _f2_nrm.cfe, _f4.fdx, _f4_Lucene40_0.frq, _f5_Lucene40_0.tip, _ey_1.del, _ez_Lucene40_0.prx, _f5_Lucene40_0.frq, _f5_Lucene40_0.tim, _f0_Lucene40_0.tim, _f7_Lucene40_0.frq, _f0_Lucene40_0.tip, _cq_Lucene40_0.prx, _f2.fdx, _f3_Lucene40_0.frq, _ez.fdt, _f2.fdt, _f1.fdx, _f2.si, _f1.fdt, _6h_1.del, _cq.fdx, _ey.fnm, _cq.fdt, _f2_Lucene40_0.prx, _f3_nrm.cfe, _6h_Lucene40_0.frq, _f7.si, _f3.si, _6h.fdt, _f3_nrm.cfs, _6h.fdx, _f0.fdx, _f1_2.del, _f1_Lucene40_0.prx, _f0.fdt, _f3.fnm, _f2.fnm, _ez_Lucene40_0.frq, _f1.fnm, _ez_nrm.cfe, _f1_nrm.cfe, _ez.fnm, _f7_Lucene40_0.tim, _f7_Lucene40_0.tip, _ey.fdt, _f2_Lucene40_0.frq, _ey.fdx, _f0_1.del, _f7.fnm, _6h_Lucene40_0.prx, _f5.fnm, _f0.si, _f1_nrm.cfs, _6h.si, _6h_nrm.cfe, _f4.si, _f4.fnm, _ez_1.del, _f1_Lucene40_0.frq, _ey.si, _6h_nrm.cfs, _6h_Lucene40_0.tim, _cq_Lucene40_0.frq, _6h_Lucene40_0.tip, _ey_nrm.cfe, _6h.fnm, _f1_Lucene40_0.tip, _f4_nrm.cfs, _f5_nrm.cfs, _f3_Lucene40_0.prx, _f5.si, _ey_nrm.cfs, _f5.fdt, _f0_Lucene40_0.frq, _f4_Lucene40_0.tim, _f5.fdx, _f1_Lucene40_0.tim, _cq_Lucene40_0.tim, _f4_nrm.cfe, _ey_Lucene40_0.prx, _f4_Lucene40_0.tip, _f5_nrm.cfe, _cq_Lucene40_0.tip, _cq_nrm.cfe, _f2_Lucene40_0.tim, _f3_Lucene40_0.tip, _f7_Lucene40_0.prx, _f3_Lucene40_0.tim, _f1.si, _f7_nrm.cfe, _cq.fnm, _cq_nrm.cfs, _f3.fdt, _f4_Lucene40_0.prx, _f7.fdx, _f7_nrm.cfs, _f5_Lucene40_0.prx, _f3.fdx, _f7.fdt, _ez.si, segments_3, _f2_Lucene40_0.tip]
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux-Java7-64/checkout/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-1339301365453/jetty1/index,segFN=segments_4,generation=4,filenames=[_g0_Lucene40_0.tip, _fu.fnm, _g0_Lucene40_0.tim, _fz.si, _fx.fdx, _fe_Lucene40_0.prx, _fu.si, _fx.fdt, _fe_1.del, _fy.fdx, _fz_nrm.cfe, _6h_Lucene40_0.prx, _fy_Lucene40_0.tip, _fy.fdt, _fy_nrm.cfe, _fz_Lucene40_0.prx, _fy_nrm.cfs, _fw_Lucene40_0.frq, _fy_Lucene40_0.tim, _fz_Lucene40_0.frq, _fz.fnm, _fz_nrm.cfs, _6h_nrm.cfe, _6h.si, _fe_Lucene40_0.frq, _fv.fnm, _fu_nrm.cfe, _fe_Lucene40_0.tip, _fv_nrm.cfs, _fe_Lucene40_0.tim, _fx_nrm.cfe, _fe_nrm.cfs, _fu_nrm.cfs, _g0.si, _6h_nrm.cfs, _6h_Lucene40_0.tim, _fv_Lucene40_0.frq, _fw.fdx, _6h_Lucene40_0.tip, _fu_Lucene40_0.prx, _fy.si, _fv.si, _fx_nrm.cfs, _fw.fdt, _fv_nrm.cfe, _fe.si, _fv_1.del, _fe_nrm.cfe, _g0.fnm, _6h_1.del, _fw.si, _6h.fnm, _fy_Lucene40_0.frq, _fu_Lucene40_0.tip, _fe.fdx, _fu_Lucene40_0.tim, _fx_Lucene40_0.tip, _fu.fdx, _fx_Lucene40_0.tim, _fe.fdt, _fe.fnm, _fw.fnm, _fu.fdt, _fw_Lucene40_0.prx, _6h_Lucene40_0.frq, _fx.si, _fx_Lucene40_0.prx, _fz.fdt, _fz.fdx, _fx_Lucene40_0.frq, _6h.fdt, _g0.fdt, _6h.fdx, _g0.fdx, _g0_nrm.cfe, _fw_Lucene40_0.tim, _fv.fdx, _fw_nrm.cfs, _fy_Lucene40_0.prx, _fx.fnm, _fw_Lucene40_0.tip, _fv.fdt, _fy.fnm, _fv_Lucene40_0.prx, _fv_Lucene40_0.tip, _fz_Lucene40_0.tip, _g0_nrm.cfs, _g0_Lucene40_0.frq, _fv_Lucene40_0.tim, _fu_Lucene40_0.frq, _fw_nrm.cfe, _g0_Lucene40_0.prx, _fz_Lucene40_0.tim, segments_4]
[junit4] 2> 29795 T1224 C33 P56580 oasc.SolrDeletionPolicy.updateCommits newest commit = 4
[junit4] 2> 29807 T1224 C33 P56580 oass.SolrIndexSearcher.<init> Opening Searcher@4c83c5d6 main
[junit4] 2> 29809 T1224 C33 P56580 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29809 T1232 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c83c5d6 main{StandardDirectoryReader(segments_4:1228 _6h(5.0):C1023/11 _fe(5.0):C1443/37 _fv(5.0):C112/25 _fu(5.0):C10 _fw(5.0):C10 _fx(5.0):C10 _fy(5.0):C10 _fz(5.0):C10 _g0(5.0):C5)}
[junit4] 2> 29812 T1368 C34 P41009 oasu.DirectUpdateHandler2.commit start commit{flags=0,version=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4] 2> 29882 T1368 C34 P41009 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux-Java7-64/checkout/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-1339301365453/jetty2/index.20120609210953,segFN=segments_4,generation=4,filenames=[_fq_Lucene40_0.prx, _fr_Lucene40_0.prx, _fo.fdt, _fo_Lucene40_0.tim, _fo.fdx, _fo_Lucene40_0.tip, _fr_nrm.cfe, _fp.fdt, _fp.fdx, _fo_1.del, _6h_Lucene40_0.prx, _fa_Lucene40_0.tim, _fr_nrm.cfs, _fp_Lucene40_0.frq, _fq.fdt, _fr.fnm, _fq.fdx, _6h.si, _6h_nrm.cfe, _fa_nrm.cfe, _fa_1.del, _fq_nrm.cfe, _fa_Lucene40_0.tip, _6h_nrm.cfs, _6h_Lucene40_0.tim, _fo_Lucene40_0.prx, _fa.fnm, _fq_nrm.cfs, _6h_Lucene40_0.tip, _fo_nrm.cfs, _6h_1.del, _6h.fnm, _fp_Lucene40_0.tim, _fq_Lucene40_0.tip, _fr.si, _fa.si, _fo.fnm, _fq_Lucene40_0.frq, _6h_Lucene40_0.frq, _fo_Lucene40_0.frq, _fr.fdx, _fo_nrm.cfe, _fr.fdt, _fr_Lucene40_0.frq, _6h.fdt, _fa_nrm.cfs, _fq_Lucene40_0.tim, _6h.fdx, _fp_Lucene40_0.tip, _fa.fdt, _fq.fnm, _fp.fnm, _fa_Lucene40_0.frq, _fa.fdx, _fp_Lucene40_0.prx, _fo.si, _fr_Lucene40_0.tim, _fp_nrm.cfs, _fr_Lucene40_0.tip, _fa_Lucene40_0.prx, _fp.si, _fp_nrm.cfe, _fq.si, segments_4]
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux-Java7-64/checkout/solr/build/solr-core/test/J1/org.apache.solr.cloud.RecoveryZkTest-1339301365453/jetty2/index.20120609210953,segFN=segments_5,generation=5,filenames=[_g0_Lucene40_0.tip, _g0_Lucene40_0.tim, _fz.si, _g2.fdt, _fx.fdx, _g2_Lucene40_0.prx, _g2.fdx, _fx.fdt, _fy.fdx, _fz_nrm.cfe, _6h_Lucene40_0.prx, _fy_Lucene40_0.tip, _fy.fdt, _fa_Lucene40_0.tim, _fy_nrm.cfe, _fz_Lucene40_0.prx, _fy_nrm.cfs, _fw_Lucene40_0.frq, _fy_Lucene40_0.tim, _fz_Lucene40_0.frq, _fz.fnm, _fz_nrm.cfs, _6h.si, _6h_nrm.cfe, _fa_nrm.cfe, _fa_1.del, _g2.si, _fa_Lucene40_0.tip, _g1_Lucene40_0.frq, _g1_Lucene40_0.prx, _fx_nrm.cfe, _g2_Lucene40_0.frq, _g0.si, _6h_nrm.cfs, _6h_Lucene40_0.tim, _fx_1.del, _fa.fnm, _g1.fnm, _6h_Lucene40_0.tip, _fw.fdx, _fy.si, _fx_nrm.cfs, _fw.fdt, _g1.si, _g0.fnm, _6h_1.del, _fw.si, _6h.fnm, _fy_Lucene40_0.frq, _fa.si, _fx_Lucene40_0.tip, _g1_Lucene40_0.tim, _fx_Lucene40_0.tim, _fw.fnm, _6h_Lucene40_0.frq, _fw_Lucene40_0.prx, _fx.si, _fx_Lucene40_0.prx, _fz.fdt, _g1.fdt, _fz.fdx, _g1.fdx, _6h.fdt, _fx_Lucene40_0.frq, _g1_Lucene40_0.tip, _g0.fdt, _fa_nrm.cfs, _6h.fdx, _g0.fdx, _g2_Lucene40_0.tim, _g0_nrm.cfe, _fa.fdt, _g1_nrm.cfs, _fa_Lucene40_0.frq, _fw_Lucene40_0.tim, _fa.fdx, _fw_nrm.cfs, _fy_Lucene40_0.prx, _fx.fnm, _fw_Lucene40_0.tip, _g2_nrm.cfs, _fy.fnm, _g1_nrm.cfe, _fz_Lucene40_0.tip, _g2.fnm, _g0_nrm.cfs, _g0_Lucene40_0.frq, _g2_nrm.cfe, _fa_Lucene40_0.prx, _fw_nrm.cfe, _g0_Lucene40_0.prx, segments_5, _g2_Lucene40_0.tip, _fz_Lucene40_0.tim]
[junit4] 2> 29882 T1368 C34 P41009 oasc.SolrDeletionPolicy.updateCommits newest commit = 5
[junit4] 2> 29885 T1368 C34 P41009 oass.SolrIndexSearcher.<init> Opening Searcher@7a2548bf main
[junit4] 2> 29886 T1368 C34 P41009 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 29887 T1428 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a2548bf main{StandardDirectoryReader(segments_5:1233:nrt _6h(5.0):C1023/11 _fa(5.0):C1403/22 _fx(5.0):C135/28 _fw(5.0):C10 _fy(5.0):C10 _fz(5.0):C10 _g0(5.0):C10 _g1(5.0):C10 _g2(5.0):C10)}
[junit4] 2> 29889 T1368 C34 P41009 /update {waitSearcher=true&commit=true&wt=javabin&commit_end_point=true&softCommit=false&version=2} {commit=} 0 77
[junit4] 2> 29890 T1224 C33 P56580 /update {waitSearcher=true&wt=javabin&commit=true&softCommit=false&version=2} {commit=} 0 182
[junit4] 2> 29892 T1227 C33 P56580 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=2560 status=0 QTime=1
[junit4] 2> 29895 T1386 C34 P41009 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=2560 status=0 QTime=1
[junit4] 2> 29898 T1227 C33 P56580 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=2560 status=0 QTime=0
[junit4] 2> 29900 T1386 C34 P41009 REQ /select {distrib=false&wt=javabin&q=*:*&version=2} hits=2560 status=0 QTime=0
[junit4] 2> 29901 T1198 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=108734584
[junit4] 2> 29901 T1198 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@18a8b019
[junit4] 2> 29902 T1198 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 29904 T1198 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5043,cumulative_deletesById=2483,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 29905 T1203 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137d49506cf0002
[junit4] 2> 29906 T1251 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29906 T1231 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29906 T1218 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29906 T1373 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29906 T1247 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29906 T1200 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39186 which had sessionid 0x137d49506cf0002
[junit4] 2> 29906 T1198 oaz.ZooKeeper.close Session: 0x137d49506cf0002 closed
[junit4] 2> 29907 T1231 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 29907 T1198 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 29908 T1231 oasc.Overseer.<init> Overseer (id=87772454286458883-127.0.0.1:56580_solr-n_0000000001) starting
[junit4] 2> 29908 T1203 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x137d49506cf0003 type:create cxid:0x60 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4] 2> 29909 T1203 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x137d49506cf0003 type:create cxid:0x61 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4] 2> 29910 T1508 oasc.Overseer$CloudStateUpdater.run Starting to work on the main queue
[junit4] 2> 29958 T1198 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=41534235
[junit4] 2> 29959 T1198 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3dd72b98
[junit4] 2> 29961 T1198 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 29963 T1198 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5043,cumulative_deletesById=2483,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 29964 T1203 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137d49506cf0003
[junit4] 2> 29964 T1251 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29965 T1373 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29965 T1231 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29965 T1247 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 29965 T1200 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39187 which had sessionid 0x137d49506cf0003
[junit4] 2> 29965 T1198 oaz.ZooKeeper.close Session: 0x137d49506cf0003 closed
[junit4] 2> 29965 T1373 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 29966 T1373 oasc.Overseer.<init> Overseer (id=87772454286458887-127.0.0.1:41009_solr-n_0000000004) starting
[junit4] 2> 29967 T1203 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x137d49506cf0007 type:create cxid:0x46 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4] 2> 29967 T1198 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 29967 T1203 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x137d49506cf0007 type:create cxid:0x47 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4] 2> 29968 T1509 oasc.Overseer$CloudStateUpdater.run Starting to work on the main queue
[junit4] 2> 29968 T1373 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:41009_solr_collection1
[junit4] 2> 29969 T1373 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 29970 T1203 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x137d49506cf0007 type:create cxid:0x56 zxid:0xfffffffffffffffe txntype:unknown reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4] 2> 30018 T1198 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=920769140
[junit4] 2> 30018 T1198 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:41009_solr_collection1
[junit4] 2> 30018 T1198 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@e9560a
[junit4] 2> 30021 T1198 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 30021 T1198 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1665,cumulative_deletesById=826,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 30024 T1198 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:41009_solr_collection1
[junit4] 2> 30024 T1203 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137d49506cf0007
[junit4] 2> 30024 T1251 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 30025 T1373 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 30025 T1247 oascc.ZkStateReader$3.process Updating live nodes
[junit4] 2> 30025 T1373 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 30025 T1200 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39208 which had sessionid 0x137d49506cf0007
[junit4] 2> 30025 T1198 oaz.ZooKeeper.close Session: 0x137d49506cf0007 closed
[junit4] 2> 30025 T1373 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4] 2> 30025 T1198 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 30078 T1203 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137d49506cf0006
[junit4] 2> 30079 T1251 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4] 2> 30079 T1198 oaz.ZooKeeper.close Session: 0x137d49506cf0006 closed
[junit4] 2> 30079 T1200 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39194 which had sessionid 0x137d49506cf0006
[junit4] 2> 30079 T1203 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137d49506cf0005
[junit4] 2> 30079 T1247 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4] 2> 30079 T1198 oaz.ZooKeeper.close Session: 0x137d49506cf0005 closed
[junit4] 2> 30080 T1200 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:39190 which had sessionid 0x137d49506cf0005
[junit4] 2> 30080 T1203 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
[junit4] 2> 30080 T1202 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
[junit4] 2> 30080 T1198 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4] 2> 30081 T1200 oazs.NIOServerCnxn$Factory.run NIOServerCnxn factory exited run method
[junit4] 2> 30082 T1198 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4] 2> 30099 T1198 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.method=testDistribSearch -Dtests.seed=8E33604CEEF4957D -Dtests.multiplier=3 -Dtests.locale=en_MT -Dtests.timezone=America/Tijuana -Dargs="-Dfile.encoding=UTF-8"
[junit4] 2>
[junit4] > (@AfterClass output)
[junit4] 2> 30130 T1198 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene40: {}, sim=DefaultSimilarity, locale=en_MT, timezone=America/Tijuana
[junit4] 2> NOTE: Linux 2.6.32-41-server amd64/Oracle Corporation 1.7.0_04 (64-bit)/cpus=8,threads=11,free=246634728,total=330301440
[junit4] 2> NOTE: All tests run in this JVM: [TestUpdate, TestGermanStemFilterFactory, TestReversedWildcardFilterFactory, SolrInfoMBeanTest, TestUtils, SampleTest, TestPseudoReturnFields, TestDFRSimilarityFactory, TestSolrQueryParser, TestSpanishLightStemFilterFactory, SuggesterTSTTest, TermVectorComponentTest, TestHTMLStripCharFilterFactory, TestMappingCharFilterFactory, HighlighterTest, TestEnglishMinimalStemFilterFactory, TestMultiWordSynonyms, OverseerTest, TestDistributedSearch, TestDelimitedPayloadTokenFilterFactory, TestShingleFilterFactory, CloudStateUpdateTest, AlternateDirectoryTest, TestGreekLowerCaseFilterFactory, BadIndexSchemaTest, TestPatternTokenizerFactory, NumericFieldsTest, SuggesterFSTTest, TestWikipediaTokenizerFactory, DistributedTermsComponentTest, RecoveryZkTest]
[junit4] 2>
[junit4] Completed on J1 in 30.18s, 1 test, 1 error <<< FAILURES!
[...truncated 600 lines...]
[...truncated 36350 lines...]
[...truncated 36350 lines...]
[...truncated 36350 lines...]
[...truncated 36350 lines...]
[...truncated 36350 lines...]