You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2012/06/13 13:44:10 UTC

[JENKINS] Solr-4.x - Build # 8 - Still Failing

Build: https://builds.apache.org/job/Solr-4.x/8/

1 tests failed.
FAILED:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch

Error Message:
Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]

Stack Trace:
java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,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([F8572ED9B28F4F41]: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:3149)
	at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:382)
	at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:451)




Build Log:
[...truncated 44896 lines...]
   [junit4]   2> 31488 T1657 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31488 T1673 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31488 T1626 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26517 which had sessionid 0x137e59e746b0002
   [junit4]   2> 31488 T1624 oaz.ZooKeeper.close Session: 0x137e59e746b0002 closed
   [junit4]   2> 31490 T1624 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 31490 T1657 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 31492 T1657 oasc.Overseer.<init> Constructing new Overseer id=87791186477776899-127.0.0.1:26518_solr-n_0000000001
   [junit4]   2> 31493 T1645 oasc.Overseer$CloudStateUpdater.amILeader WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:289)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.amILeader(Overseer.java:174)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.run(Overseer.java:104)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 31493 T1645 oasc.Overseer$CloudStateUpdater.amILeader According to ZK I (id=87791186477776898-127.0.0.1:26516_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 31495 T1657 oasc.Overseer.processLeaderNodesChanged Leader nodes changed for collection: collection1 nodes now:[shard1]
   [junit4]   2> 31495 T1657 oasc.Overseer.announceLeader Leader change pooled: http://127.0.0.1:26518/solr/collection1/
   [junit4]   2> 31496 T1657 oasc.Overseer.processLeaderNodesChanged Leader nodes changed for collection: control_collection nodes now:[]
   [junit4]   2> 31497 T1657 oasc.Overseer.coreChanged Core change pooled: 127.0.0.1:26518_solr states:[coll:collection1 core:collection1 props:{num_shards=1, shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:26518_solr, base_url=http://127.0.0.1:26518/solr}]
   [junit4]   2> 31498 T1657 oasc.Overseer.coreChanged Core change pooled: 127.0.0.1:26520_solr states:[coll:collection1 core:collection1 props:{num_shards=1, shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:26520_solr, base_url=http://127.0.0.1:26520/solr}]
   [junit4]   2> 31499 T1797 oascc.ZkStateReader.updateCloudState Manual update of cluster state initiated
   [junit4]   2> 31500 T1797 oascc.ZkStateReader.updateCloudState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31502 T1797 oasc.Overseer$CloudStateUpdater.run Announcing new cluster state
   [junit4]   2> 31504 T1722 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31504 T1657 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31504 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31504 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31542 T1624 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1768267199
   [junit4]   2> 31542 T1624 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7ce3f6a3
   [junit4]   2> 31544 T1624 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 31545 T1624 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=1632,cumulative_deletesById=800,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 31547 T1629 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137e59e746b0003
   [junit4]   2> 31548 T1673 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31548 T1677 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31548 T1626 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26519 which had sessionid 0x137e59e746b0003
   [junit4]   2> 31548 T1624 oaz.ZooKeeper.close Session: 0x137e59e746b0003 closed
   [junit4]   2> 31550 T1624 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 31550 T1722 oasu.PeerSync.sync PeerSync: core=collection1 url=127.0.0.1:26513/solr START replicas=[] nUpdates=100
   [junit4]   2> 31554 T1722 oasu.PeerSync.sync PeerSync: core=collection1 url=127.0.0.1:26513/solr DONE. sync succeeded
   [junit4]   2> 31554 T1722 oasc.SyncStrategy.syncToMe try and ask http://127.0.0.1:26518/solr/collection1/ to sync
   [junit4]   2> 31556 T1728 C144 P26520 oasu.PeerSync.sync PeerSync: core=collection1 url=127.0.0.1:26513/solr START replicas=[127.0.0.1:26520/solr/collection1/] nUpdates=100
   [junit4]   2> 31560 T1726 C144 P26520 REQ /get {distrib=false&qt=/get&wt=javabin&version=2&getVersions=100} status=0 QTime=3 
   [junit4]   2> 31562 T1728 C144 P26520 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=127.0.0.1:26513/solr  Received 100 versions from 127.0.0.1:26520/solr/collection1/
   [junit4]   2> 31562 T1728 C144 P26520 oasu.PeerSync.handleVersions PeerSync: core=collection1 url=127.0.0.1:26513/solr  Our versions are newer. ourLowThreshold=1404659014299549696 otherHigh=1404659014849003520
   [junit4]   2> 31563 T1728 C144 P26520 oasu.PeerSync.sync PeerSync: core=collection1 url=127.0.0.1:26513/solr DONE. sync succeeded
   [junit4]   2> 31563 T1728 C144 P26520 REQ /get {sync=127.0.0.1:26520/solr/collection1/&getVersions=100&distrib=false&qt=/get&wt=javabin&version=2} status=0 QTime=7 
   [junit4]   2> 31564 T1722 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:26520_solr_collection1
   [junit4]   2> 31566 T1722 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 31569 T1722 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 31576 T1722 oasc.Overseer.<init> Constructing new Overseer id=87791186477776903-127.0.0.1:26520_solr-n_0000000004
   [junit4]   2> 31578 T1722 oasc.Overseer.processLeaderNodesChanged Leader nodes changed for collection: collection1 nodes now:[shard1]
   [junit4]   2> 31579 T1722 oasc.Overseer.announceLeader Leader change pooled: http://127.0.0.1:26520/solr/collection1/
   [junit4]   2> 31579 T1722 oasc.Overseer.processLeaderNodesChanged Leader nodes changed for collection: control_collection nodes now:[]
   [junit4]   2> 31581 T1722 oasc.Overseer.coreChanged Core change pooled: 127.0.0.1:26520_solr states:[coll:collection1 core:collection1 props:{num_shards=1, shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:26520_solr, base_url=http://127.0.0.1:26520/solr}]
   [junit4]   2> 31581 T1722 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31582 T1800 oascc.ZkStateReader.updateCloudState Manual update of cluster state initiated
   [junit4]   2> 31582 T1800 oascc.ZkStateReader.updateCloudState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31584 T1800 oasc.Overseer$CloudStateUpdater.run Announcing new cluster state
   [junit4]   2> 31586 T1722 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31586 T1677 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31586 T1673 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 31602 T1624 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=546684440
   [junit4]   2> 31602 T1624 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:26520_solr_collection1
   [junit4]   2> 31603 T1624 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@30860066
   [junit4]   2> 31606 T1624 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 31607 T1624 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=849,cumulative_deletesById=411,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 31610 T1624 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:26520_solr_collection1
   [junit4]   2> 31611 T1629 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137e59e746b0007
   [junit4]   2> 31613 T1677 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31613 T1673 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 31613 T1626 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26536 which had sessionid 0x137e59e746b0007
   [junit4]   2> 31613 T1624 oaz.ZooKeeper.close Session: 0x137e59e746b0007 closed
   [junit4]   2> 31614 T1624 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 31666 T1629 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137e59e746b0006
   [junit4]   2> 31667 T1677 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 31667 T1626 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26526 which had sessionid 0x137e59e746b0006
   [junit4]   2> 31667 T1624 oaz.ZooKeeper.close Session: 0x137e59e746b0006 closed
   [junit4]   2> 31668 T1629 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137e59e746b0005
   [junit4]   2> 31669 T1673 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 31669 T1626 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26523 which had sessionid 0x137e59e746b0005
   [junit4]   2> 31669 T1624 oaz.ZooKeeper.close Session: 0x137e59e746b0005 closed
   [junit4]   2> 31670 T1629 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
   [junit4]   2> 31670 T1628 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
   [junit4]   2> 31670 T1624 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
   [junit4]   2> 31871 T1626 oazs.NIOServerCnxn$Factory.run NIOServerCnxn factory exited run method
   [junit4]   2> 31872 T1624 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
   [junit4]   2> 31910 T1624 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.method=testDistribSearch -Dtests.seed=F8572ED9B28F4F41 -Dtests.locale=en_MT -Dtests.timezone=America/Montevideo -Dargs="-Dfile.encoding=ISO8859-1"
   [junit4]   2>
   [junit4]    > (@AfterClass output)
   [junit4]   2> 31944 T1624 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene40: {}, sim=RandomSimilarityProvider(queryNorm=true,coord=true): {}, locale=en_MT, timezone=America/Montevideo
   [junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=10,free=109590288,total=360382464
   [junit4]   2> NOTE: All tests run in this JVM: [TestLRUCache, TestDistributedGrouping, TestCJKTokenizerFactory, SuggesterFSTTest, TestRandomFaceting, TestJapaneseKatakanaStemFilterFactory, TestFiltering, TestGermanStemFilterFactory, FieldAnalysisRequestHandlerTest, StatsComponentTest, TestHyphenationCompoundWordTokenFilterFactory, CloudStateTest, TestDFRSimilarityFactory, TestSystemIdResolver, ZkSolrClientTest, FieldMutatingUpdateProcessorTest, CoreAdminHandlerTest, SolrPluginUtilsTest, LoggingHandlerTest, TestMultiWordSynonyms, TestRealTimeGet, SpellPossibilityIteratorTest, TestBadConfig, TestLFUCache, MBeansHandlerTest, URLClassifyProcessorTest, TestExtendedDismaxParser, TestMappingCharFilterFactory, TestCzechStemFilterFactory, TestJapanesePartOfSpeechStopFilterFactory, EchoParamsTest, TestPortugueseStemFilterFactory, TestMergePolicyConfig, TestUtils, SuggesterTest, TestFunctionQuery, TestIndexSearcher, OpenExchangeRatesOrgProviderTest, TestUAX29URLEmailTokenizerFactory, TestConfig, LegacyHTMLStripCharFilterTest, TestSolrCoreProperties, TestHunspellStemFilterFactory, TestPatternReplaceFilterFactory, TestSwedishLightStemFilterFactory, TestPropInject, TestBM25SimilarityFactory, TestPersianNormalizationFilterFactory, TestStandardFactories, SpellCheckCollatorTest, TestTrimFilterFactory, MoreLikeThisHandlerTest, SystemInfoHandlerTest, TestGermanMinimalStemFilterFactory, FastVectorHighlighterTest, DOMUtilTest, TestBinaryField, TestCollationField, TestSort, SpellCheckComponentTest, DirectUpdateHandlerOptimizeTest, TestBulgarianStemFilterFactory, TestReplicationHandler, FileBasedSpellCheckerTest, TestJapaneseReadingFormFilterFactory, TestBinaryResponseWriter, TestArbitraryIndexDir, TestValueSourceCache, TestPropInjectDefaults, BadComponentTest, TestCJKBigramFilterFactory, TestRecovery, TestWikipediaTokenizerFactory, ReturnFieldsTest, TestFinnishLightStemFilterFactory, TestHindiFilters, AutoCommitTest, TestJmxMonitoredMap, SnowballPorterFilterFactoryTest, HighlighterTest, TestElisionFilterFactory, TestJapaneseBaseFormFilterFactory, TestJapaneseTokenizerFactory, DoubleMetaphoneFilterFactoryTest, TestWordDelimiterFilterFactory, RequestHandlersTest, TestGermanNormalizationFilterFactory, SpatialFilterTest, TestGreekLowerCaseFilterFactory, RequiredFieldsTest, SimpleFacetsTest, UpdateParamsTest, DirectUpdateHandlerTest, TestArabicFilters, TestPatternTokenizerFactory, FullSolrCloudDistribCmdsTest, BasicZkTest, TestPhraseSuggestions, NodeStateWatcherTest, SolrInfoMBeanTest, CopyFieldTest, TestTurkishLowerCaseFilterFactory, TestLuceneMatchVersion, SortByFunctionTest, BasicFunctionalityTest, DisMaxRequestHandlerTest, DateFieldTest, FileUtilsTest, PolyFieldTest, HighlighterConfigTest, TestJoin, TestPortugueseMinimalStemFilterFactory, FullSolrCloudTest, TestReversedWildcardFilterFactory, TestUpdate, IndexSchemaTest, TestCJKWidthFilterFactory, DateMathParserTest, QueryElevationComponentTest, TestPorterStemFilterFactory, LeaderElectionIntegrationTest, TestPHPSerializedResponseWriter, TestMultiCoreConfBootstrap, TestSlowSynonymFilter, TestBeiderMorseFilterFactory, ZkControllerTest, TestRussianLightStemFilterFactory, DistanceFunctionTest, UUIDFieldTest, PrimUtilsTest, JSONWriterTest, MultiTermTest, TestSolrDeletionPolicy1, SearchHandlerTest, TestCodecSupport, TestKStemFilterFactory, TestNumberUtils, TestLatvianStemFilterFactory, CacheHeaderTest, TestChineseFilterFactory, TestJmxIntegration, NumericFieldsTest, TestTypeTokenFilterFactory, TestRangeQuery, TestSolrDeletionPolicy2, BadIndexSchemaTest, PrimitiveFieldTypeTest, TestCapitalizationFilterFactory, StandardRequestHandlerTest, TestXIncludeConfig, TimeZoneUtilsTest, TestCollationKeyRangeQueries, TestStopFilterFactory, PluginInfoTest, TestPatternReplaceCharFilterFactory, TestFoldingMultitermQuery, TestReverseStringFilterFactory, TestSynonymMap, TestQueryTypes, XmlUpdateRequestHandlerTest, SOLR749Test, TestGermanLightStemFilterFactory, DistributedQueryElevationComponentTest, ZkNodePropsTest, ResourceLoaderTest, MinimalSchemaTest, TestLMJelinekMercerSimilarityFactory, TestFrenchLightStemFilterFactory, SolrCoreTest, RecoveryZkTest]
   [junit4]   2> 
   [junit4] Completed in 31.96s, 1 test, 1 error <<< FAILURES!
[...truncated 359 lines...]

[...truncated 45356 lines...]

[...truncated 45356 lines...]

[...truncated 45356 lines...]

[...truncated 45356 lines...]

[...truncated 45356 lines...]



[JENKINS] Solr-4.x - Build # 9 - Still Failing

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Solr-4.x/9/

1 tests failed.
FAILED:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch

Error Message:
Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,6,]

Stack Trace:
java.lang.RuntimeException: Thread threw an uncaught exception, thread: Thread[Lucene Merge Thread #2,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([18DE9A9DE2F3DF31]: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:3149)
	at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:382)
	at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:451)




Build Log:
[...truncated 46889 lines...]
   [junit4]   2> 26469 T1539 oasc.Overseer.coreChanged Core change pooled: 127.0.0.1:56723_solr states:[coll:collection1 core:collection1 props:{num_shards=1, shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56723_solr, base_url=http://127.0.0.1:56723/solr}]
   [junit4]   2> 26469 T1539 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 26470 T1619 oascc.ZkStateReader.updateCloudState Manual update of cluster state initiated
   [junit4]   2> 26470 T1619 oascc.ZkStateReader.updateCloudState Updating cloud state from ZooKeeper... 
   [junit4]   2> 26470 T1539 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:56723_solr_collection1
   [junit4]   2> 26471 T1619 oasc.Overseer$CloudStateUpdater.run Announcing new cluster state
   [junit4]   2> 26471 T1539 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 26478 T1483 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 26478 T1479 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 26480 T1539 oascc.ZkStateReader$2.process A cluster state change has occurred
   [junit4]   2> 26481 T1539 oasc.Overseer.processLeaderNodesChanged Leader nodes changed for collection: collection1 nodes now:[shard1]
   [junit4]   2> 26481 T1539 oasc.Overseer.announceLeader Leader change pooled: http://127.0.0.1:56723/solr/collection1/
   [junit4]   2> 26514 T1451 oasc.Overseer$CloudStateUpdater.amILeader WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:289)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.amILeader(Overseer.java:174)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.run(Overseer.java:104)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 26514 T1451 oasc.Overseer$CloudStateUpdater.amILeader According to ZK I (id=87796917491662850-127.0.0.1:33016_solr-n_0000000000) am no longer a leader.
   [junit4]   2> 26517 T1430 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=829818861
   [junit4]   2> 26518 T1430 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:56723_solr_collection1
   [junit4]   2> 26518 T1430 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@60df997c
   [junit4]   2> 26520 T1430 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 26521 T1430 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=1027,cumulative_deletesById=508,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 26522 T1430 oasc.RecoveryStrategy.close WARNING Stopping recovery for core collection1 zkNodeName=127.0.0.1:56723_solr_collection1
   [junit4]   2> 26523 T1435 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137ead4cf770007
   [junit4]   2> 26524 T1479 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 26524 T1483 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 26524 T1432 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:32343 which had sessionid 0x137ead4cf770007
   [junit4]   2> 26524 T1430 oaz.ZooKeeper.close Session: 0x137ead4cf770007 closed
   [junit4]   2> 26525 T1430 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 26577 T1435 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137ead4cf770006
   [junit4]   2> 26579 T1432 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:23287 which had sessionid 0x137ead4cf770006
   [junit4]   2> 26579 T1483 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 26579 T1430 oaz.ZooKeeper.close Session: 0x137ead4cf770006 closed
   [junit4]   2> 26580 T1435 oazs.PrepRequestProcessor.pRequest Processed session termination for sessionid: 0x137ead4cf770005
   [junit4]   2> 26580 T1479 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 26580 T1432 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35629 which had sessionid 0x137ead4cf770005
   [junit4]   2> 26580 T1430 oaz.ZooKeeper.close Session: 0x137ead4cf770005 closed
   [junit4]   2> 26581 T1435 oazs.PrepRequestProcessor.run PrepRequestProcessor exited loop!
   [junit4]   2> 26581 T1434 oazs.SyncRequestProcessor.run SyncRequestProcessor exited!
   [junit4]   2> 26581 T1430 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
   [junit4]   2> 26924 T1618 oasc.Overseer$CloudStateUpdater.amILeader WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:289)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.amILeader(Overseer.java:174)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.run(Overseer.java:104)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 26924 T1618 oasc.Overseer$CloudStateUpdater.amILeader According to ZK I (id=87796917491662851-127.0.0.1:31356_solr-n_0000000001) am no longer a leader.
   [junit4]   2> 26979 T1619 oasc.Overseer$CloudStateUpdater.amILeader WARNING  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:118)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:42)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:927)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:289)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:286)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.amILeader(Overseer.java:174)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$CloudStateUpdater.run(Overseer.java:104)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:679)
   [junit4]   2> 
   [junit4]   2> 26979 T1619 oasc.Overseer$CloudStateUpdater.amILeader According to ZK I (id=87796917491662855-127.0.0.1:56723_solr-n_0000000004) am no longer a leader.
   [junit4]   2> 27407 T1450 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27407 T1450 oasc.Overseer$3$1.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27407 T1450 oasc.Overseer$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27407 T1450 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 27464 T1463 oasc.Overseer$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27464 T1463 oasc.Overseer$3$1.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27464 T1463 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 27464 T1463 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27464 T1463 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 27525 T1539 oasc.Overseer$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27525 T1539 oascc.ZkStateReader$3.process Updating live nodes
   [junit4]   2> 27525 T1539 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27525 T1539 oasc.Overseer$3$1.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 27525 T1539 oaz.ClientCnxn$EventThread.run EventThread shut down
   [junit4]   2> 27669 T1433 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
   [junit4]   2> 27690 T1432 oazs.NIOServerCnxn$Factory.run NIOServerCnxn factory exited run method
   [junit4]   2> 27690 T1430 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
   [junit4]   2> 27721 T1430 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.method=testDistribSearch -Dtests.seed=18DE9A9DE2F3DF31 -Dtests.locale=el -Dtests.timezone=Africa/Juba -Dargs="-Dfile.encoding=ISO8859-1"
   [junit4]   2>
   [junit4]    > (@AfterClass output)
   [junit4]   2> 27882 T1430 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene40: {}, sim=RandomSimilarityProvider(queryNorm=true,coord=true): {}, locale=el, timezone=Africa/Juba
   [junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=147080872,total=268566528
   [junit4]   2> NOTE: All tests run in this JVM: [UpdateParamsTest, DOMUtilTest, HighlighterConfigTest, NotRequiredUniqueKeyTest, SolrCmdDistributorTest, CopyFieldTest, TestPatternReplaceFilterFactory, TestSpanishLightStemFilterFactory, TestRangeQuery, FullSolrCloudDistribCmdsTest, TestMultiCoreConfBootstrap, ZkControllerTest, TestJoin, TestStopFilterFactory, TestGreekStemFilterFactory, TestItalianLightStemFilterFactory, QueryParsingTest, StatsComponentTest, TestCodecSupport, TestUpdate, TestGermanLightStemFilterFactory, UniqFieldsUpdateProcessorFactoryTest, CloudStateUpdateTest, TestCollationKeyFilterFactory, TestTurkishLowerCaseFilterFactory, TestRandomFaceting, SuggesterFSTTest, DistributedSpellCheckComponentTest, MoreLikeThisHandlerTest, TestIrishLowerCaseFilterFactory, IndexSchemaTest, TestCapitalizationFilterFactory, TestDelimitedPayloadTokenFilterFactory, TestReplicationHandler, TermsComponentTest, TestSearchPerf, SpellCheckCollatorTest, TestGermanNormalizationFilterFactory, IndexSchemaRuntimeFieldTest, TestPatternTokenizerFactory, TestMappingCharFilterFactory, TestSwedishLightStemFilterFactory, TestSolrDeletionPolicy1, MinimalSchemaTest, CommonGramsFilterFactoryTest, TestFiltering, TestGalicianStemFilterFactory, BadIndexSchemaTest, TestExtendedDismaxParser, DistributedTermsComponentTest, DocumentAnalysisRequestHandlerTest, TestRemoteStreaming, SpatialFilterTest, TestPorterStemFilterFactory, TestLRUCache, FileUtilsTest, TestTrie, TestLatvianStemFilterFactory, TestRussianFilters, DoubleMetaphoneFilterFactoryTest, SOLR749Test, TestSolrXMLSerializer, TestIBSimilarityFactory, BasicDistributedZkTest, TestWriterPerf, CSVRequestHandlerTest, TestRemoveDuplicatesTokenFilterFactory, DefaultValueUpdateProcessorTest, IndexReaderFactoryTest, TestGalicianMinimalStemFilterFactory, TestPersianNormalizationFilterFactory, MultiTermTest, SolrInfoMBeanTest, SystemInfoHandlerTest, TestMultiWordSynonyms, SortByFunctionTest, SearchHandlerTest, TestKStemFilterFactory, TestHTMLStripCharFilterFactory, BasicZkTest, NumericFieldsTest, TestSlowSynonymFilter, TestNorwegianMinimalStemFilterFactory, TestBrazilianStemFilterFactory, ResourceLoaderTest, TestRussianLightStemFilterFactory, TestMergePolicyConfig, TestDocSet, TestLFUCache, TestSynonymFilterFactory, AlternateDirectoryTest, NodeStateWatcherTest, TestSystemIdResolver, ZkNodePropsTest, RecoveryZkTest]
   [junit4]   2> 
   [junit4] Completed in 27.99s, 1 test, 1 error <<< FAILURES!
[...truncated 612 lines...]

[...truncated 47602 lines...]

[...truncated 47602 lines...]

[...truncated 47602 lines...]

[...truncated 47602 lines...]

[...truncated 47602 lines...]