Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/590/
2 tests failed. REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure Error Message: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed Stack Trace: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed at __randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:57B3848BC64D70E4]:0) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155) at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131) ... 48 more Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398) at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34) ... 49 more FAILED: org.apache.solr.cloud.MultiThreadedOCPTest.testDistribSearch Error Message: We have a failed SPLITSHARD task Stack Trace: java.lang.AssertionError: We have a failed SPLITSHARD task at __randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:D25D8560A3B7FFF9]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125) at org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 11473 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-53BB0B78D4E89FC5-001/init-core-data-001 [junit4] 2> 132304 T483 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true) [junit4] 2> 132304 T483 oas.SolrTestCaseJ4.initCore ####initCore [junit4] 2> 132304 T483 oas.SolrTestCaseJ4.initCore ####initCore end [junit4] 2> 132309 T483 oas.SolrTestCaseJ4.setUp ###Starting testReplay [junit4] 2> 132322 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 132331 T484 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 132531 T483 oasc.ZkTestServer.run start zk server on port:34561 [junit4] 2> 132866 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 132915 T485 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running [junit4] 2> 134169 T490 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2338eb14 name:ZooKeeperConnection Watcher:127.0.0.1:34561/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 134169 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 134176 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 134179 T492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71ba2933 name:ZooKeeperConnection Watcher:127.0.0.1:34561 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 134179 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 134264 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 134266 T494 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b224c45 name:ZooKeeperConnection Watcher:127.0.0.1:34561 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 134267 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 134273 T483 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 134300 T483 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 134324 T483 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 134327 T483 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 134329 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 134420 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 134433 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 134435 T496 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f1cf161 name:ZooKeeperConnection Watcher:127.0.0.1:34561/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 134435 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 134443 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 134446 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 134476 T483 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34561_solr [junit4] 2> 134477 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 134480 T483 oasc.Overseer.start Overseer (id=92213278593843203-127.0.0.1:34561_solr-n_0000000000) starting [junit4] 2> 134508 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 134520 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 134524 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 134528 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 134551 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 134560 T498 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 134575 T497 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 134576 T497 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue. [junit4] 2> 134577 T497 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 134641 T497 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 134642 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 134645 T497 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 134648 T497 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 134649 T497 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 134653 T500 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 134756 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 134770 T483 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34561 34561 [junit4] 2> 134889 T484 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34561 34561 [junit4] 2> 134890 T483 oas.SolrTestCaseJ4.tearDown ###Ending testReplay [junit4] 2> 134891 T497 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:34561_solr [junit4] 2> 134900 T483 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment [junit4] 2> 134902 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 134902 T502 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 134904 T501 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> 135002 T483 oasc.ZkTestServer.run start zk server on port:34567 [junit4] 2> 135003 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135007 T508 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@102d0abe name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135007 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135008 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135009 T510 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@548dcd63 name:ZooKeeperConnection Watcher:127.0.0.1:34567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135010 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135012 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135014 T512 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17373182 name:ZooKeeperConnection Watcher:127.0.0.1:34567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135014 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135014 T483 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 135018 T483 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 135021 T483 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 135024 T483 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 135026 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 135035 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135037 T514 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24ff9528 name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135037 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135039 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 135042 T483 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 135046 T515 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135046 T516 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135046 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135048 T518 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40af72ba name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135048 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135049 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 135052 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 135058 T483 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34567_solr [junit4] 2> 135058 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 135061 T483 oasc.Overseer.start Overseer (id=92213278738284548-127.0.0.1:34567_solr-n_0000000000) starting [junit4] 2> 135063 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 135068 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 135072 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 135076 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 135081 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 135086 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 135093 T520 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 135095 T519 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 135098 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 135099 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 135099 T519 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 135111 T519 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 135115 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135116 T515 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 135116 T516 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 135598 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 135628 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 135636 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135636 T483 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 135638 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 135639 T516 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 135639 T515 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 135641 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135643 T523 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b702644 name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135643 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135645 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 135648 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135648 T483 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 135652 T516 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135652 T524 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135654 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135654 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 135655 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 135656 T519 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 135659 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135662 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 135668 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135672 T521 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 135775 T524 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 135775 T516 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 135776 T483 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 135780 T516 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 135780 T524 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 135782 T483 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34567 34567 [junit4] 2> 135825 T502 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34567 34567 [junit4] 2> 135826 T483 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment [junit4] 2> 135826 T519 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:34567_solr [junit4] 2> 135827 T525 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> 135836 T483 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure [junit4] 2> 135837 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 135837 T526 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 135937 T483 oasc.ZkTestServer.run start zk server on port:34574 [junit4] 2> 135938 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135950 T532 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65c9a3b8 name:ZooKeeperConnection Watcher:127.0.0.1:34574 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135950 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135953 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135955 T534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c78440 name:ZooKeeperConnection Watcher:127.0.0.1:34574 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135955 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135956 T483 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 135960 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135962 T536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26ebec38 name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135962 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135962 T483 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 135965 T483 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 135968 T483 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 135970 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 135974 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135975 T538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3852eabd name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135976 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135977 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 135981 T483 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 135984 T539 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135984 T540 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 135985 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 135986 T542 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40beb5f0 name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 135987 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 135988 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 135991 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 135996 T483 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34574_solr [junit4] 2> 135997 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 136000 T483 oasc.Overseer.start Overseer (id=92213278799495172-127.0.0.1:34574_solr-n_0000000000) starting [junit4] 2> 136002 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 136006 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 136010 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 136015 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 136019 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 136023 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 136030 T544 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 136032 T543 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 137034 T545 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 137036 T543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 137037 T543 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 137037 T543 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 137038 T543 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 137041 T545 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 137042 T539 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 137042 T540 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 137534 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 137545 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 137552 T545 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 137553 T483 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 137554 T543 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 137557 T545 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 137557 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 137560 T543 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 137560 T543 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 137563 T545 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 137666 T539 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 137666 T540 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 138035 T544 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK [junit4] 2> 138722 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 138731 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 138733 T547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5633c113 name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 138733 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 138733 T543 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:34574_solr [junit4] 2> 138734 T548 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> 138738 T483 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:34574_solr [junit4] 2> 138738 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 138741 T483 oasc.Overseer.start Overseer (id=92213278799495173-127.0.0.1:34574_solr-n_0000000001) starting [junit4] 2> 138753 T550 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 138755 T549 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 138757 T549 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 138758 T549 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 138759 T549 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 138762 T551 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 138763 T540 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 138763 T539 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 138817 T551 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 138817 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 138819 T549 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 138824 T483 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92213278799495171-node1_core1-n_0000000002 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155) [junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 138827 T540 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 138828 T549 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:184) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:181) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:181) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1100) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:358) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:240) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 138829 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 138829 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 138831 T551 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 138834 T551 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 138835 T549 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1 [junit4] 2> 138838 T551 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 138941 T539 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 138941 T540 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 139833 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 139833 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 140837 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 140838 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 141842 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 141842 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 142846 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 142847 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 143851 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 143852 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 144855 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 144856 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 145859 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 145860 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 146863 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 146864 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 147867 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 147869 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 148871 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 148872 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 149875 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 149876 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 150880 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 150880 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 151884 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 151884 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 152889 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 152889 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 153893 T552 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 153893 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 153897 T552 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144) [junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131) [junit4] 2> ... 10 more [junit4] 2> Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136) [junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34) [junit4] 2> ... 11 more [junit4] 2> [junit4] 2> 153899 T540 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 153900 T539 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 153903 T483 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34574 34574 [junit4] 2> 154022 T526 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34574 34574 [junit4] 2> 154023 T483 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure [junit4] 2> 154024 T549 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:34574_solr [junit4] 2> 154025 T553 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=53BB0B78D4E89FC5 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=ko_KR -Dtests.timezone=Indian/Antananarivo -Dtests.file.encoding=UTF-8 [junit4] ERROR 18.3s J0 | OverseerTest.testOverseerFailure <<< [junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed [junit4] > at __randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:57B3848BC64D70E4]:0) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144) [junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155) [junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131) [junit4] > ... 48 more [junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) [junit4] > at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457) [junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136) [junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34) [junit4] > ... 49 more [junit4] 2> 154115 T483 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem [junit4] 2> 154116 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 154117 T554 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 154217 T483 oasc.ZkTestServer.run start zk server on port:17441 [junit4] 2> 154218 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 154221 T560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d2c47e9 name:ZooKeeperConnection Watcher:127.0.0.1:17441 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 154222 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 154224 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 154226 T562 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@427a26e2 name:ZooKeeperConnection Watcher:127.0.0.1:17441 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 154226 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 154226 T483 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 154230 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 154231 T564 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a6bdb60 name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 154232 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 154232 T483 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 154235 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 154236 T566 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64109ce7 name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 154236 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 154238 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 154240 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 154245 T483 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:17441_solr [junit4] 2> 154245 T483 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 154247 T483 oasc.Overseer.start Overseer (id=92213279997493251-127.0.0.1:17441_solr-n_0000000000) starting [junit4] 2> 154250 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 154253 T483 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 154256 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 154260 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 154263 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 154267 T483 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 154273 T568 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 154274 T483 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 154274 T567 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 154276 T483 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 154278 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 154281 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 154283 T570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d471f2d name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 154283 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 154285 T483 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 154288 T483 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1 [junit4] 2> 154290 T571 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 154291 T572 oascc.ZkStateReader$3.process Updating live nodes... (1) [junit4] 2> 154293 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 154294 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 154295 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 154295 T567 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3] [junit4] 2> 154296 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 154299 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 154300 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 154300 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 154793 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 154803 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3 [junit4] 2> 154809 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 154811 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 154811 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 154815 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 154816 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 154816 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 154818 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 154921 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 154921 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 155311 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 155319 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 155324 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155324 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155324 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155326 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155326 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 155330 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 155331 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 155331 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 155333 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155436 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 155436 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 155826 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 155834 T483 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 155840 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155840 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155840 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155841 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 155845 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155947 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 155947 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 155995 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155995 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155995 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155996 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 155997 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 155997 T567 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":"", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 156001 T567 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"deletecore", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":""} [junit4] 2> 156004 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156005 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 156005 T567 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3] [junit4] 2> 156005 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 156008 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156110 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 156110 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 156499 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election [junit4] 2> 156508 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3 [junit4] 2> 156514 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156514 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156514 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156516 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156516 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 156521 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 156521 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 156521 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 156524 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 156626 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 156626 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 157016 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election [junit4] 2> 157024 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2 [junit4] 2> 157029 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157029 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157029 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157031 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157031 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 157035 T567 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 157035 T567 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 157035 T567 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 157038 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157141 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 157141 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 157531 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election [junit4] 2> 157539 T483 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1 [junit4] 2> 157544 T574 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157544 T575 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157544 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157545 T567 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... [junit4] 2> 157548 T573 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 157651 T571 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 157651 T572 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 157699 T571 oascc.ZkStateReader$3.process Updating live nodes... (0) [junit4] 2> 157701 T483 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:17441 17441 [junit4] 2> 157875 T554 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:17441 17441 [junit4] 2> 157876 T483 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem [junit4] 2> 157876 T567 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:17441_solr [junit4] 2> 157877 T576 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> 157884 T483 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger [junit4] 2> 157885 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 157886 T577 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 157986 T483 oasc.ZkTestServer.run start zk server on port:25338 [junit4] 2> 157987 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 157990 T583 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64cbff21 name:ZooKeeperConnection Watcher:127.0.0.1:25338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 157991 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 157993 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 157994 T585 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e353af0 name:ZooKeeperConnection Watcher:127.0.0.1:25338 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 157995 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 157995 T483 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 157999 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 158000 T587 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cfd7642 name:ZooKeeperConnection Watcher:127.0.0.1:25338/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 158000 T483 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 158001 T483 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 158003 T483 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 158004 T589 oascc.ConnectionManager.pro [...truncated too long message...] ndex [CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest2_shard1_replica1/data/index;done=false>>] [junit4] 2> 3780374 T10355 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest2_shard1_replica1/data/index [junit4] 2> 3780374 T10355 oasc.SolrCore.close [ocptest_shardsplit_shard4_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@853f143 [junit4] 2> 3780383 T10355 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0} [junit4] 2> 3780383 T10355 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState [junit4] 2> 3780384 T10355 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter [junit4] 2> 3780384 T10355 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser [junit4] 2> 3780385 T10355 oasc.SolrCore.closeSearcher [ocptest_shardsplit_shard4_replica1] Closing main searcher on request. [junit4] 2> 3780385 T10355 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked [junit4] 2> 3780385 T10355 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index [CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index;done=false>>] [junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index [junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data [CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data;done=false>>] [junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.close Closing directory: ./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data [junit4] 2> 3780387 T11942 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:37404_nzjt%2Fpm [junit4] 2> 3780388 T11944 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288) [junit4] 2> [junit4] 2> 3781888 T10469 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 3781890 T10355 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/nzjt/pm,null} [junit4] 2> 3784332 T10355 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch [junit4] 2> 3784334 T10355 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:21266 21266 [junit4] 2> 3784477 T10356 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:21266 21266 [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=MultiThreadedOCPTest -Dtests.method=testDistribSearch -Dtests.seed=53BB0B78D4E89FC5 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=ko -Dtests.timezone=Antarctica/Casey -Dtests.file.encoding=UTF-8 [junit4] FAILURE 58.7s J0 | MultiThreadedOCPTest.testDistribSearch <<< [junit4] > Throwable #1: java.lang.AssertionError: We have a failed SPLITSHARD task [junit4] > at __randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:D25D8560A3B7FFF9]:0) [junit4] > at org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125) [junit4] > at org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 3784487 T10355 oas.SolrTestCaseJ4.deleteCore ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001 [junit4] 2> 58682 T10354 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{}, sim=DefaultSimilarity, locale=ko, timezone=Antarctica/Casey [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=225480784,total=368574464 [junit4] 2> NOTE: All tests run in this JVM: [TestSurroundQueryParser, TestRandomMergePolicy, TestStressReorder, TestPartialUpdateDeduplication, PathHierarchyTokenizerFactoryTest, TestManagedSynonymFilterFactory, SuggesterWFSTTest, SignatureUpdateProcessorFactoryTest, DistributedSpellCheckComponentTest, TestRangeQuery, JsonLoaderTest, TestSolrDeletionPolicy1, OverseerTest, RollingRestartTest, ExternalFileFieldSortTest, TestBinaryResponseWriter, TestRemoteStreaming, TriLevelCompositeIdRoutingTest, CurrencyFieldOpenExchangeTest, XmlUpdateRequestHandlerTest, TestHashPartitioner, SpellPossibilityIteratorTest, TestDynamicFieldResource, TestComponentsName, TestReRankQParserPlugin, DateFieldTest, ReplicationFactorTest, TestFieldResource, StressHdfsTest, TestSimpleQParserPlugin, TestManagedSchema, TestLuceneMatchVersion, TestConfig, TestFieldTypeCollectionResource, CoreAdminHandlerTest, DocExpirationUpdateProcessorFactoryTest, CursorPagingTest, SyncSliceTest, TestCollapseQParserPlugin, TestRequestStatusCollectionAPI, BasicFunctionalityTest, TestComplexPhraseQParserPlugin, ParsingFieldUpdateProcessorsTest, TestCloudManagedSchemaConcurrent, ResourceLoaderTest, PrimUtilsTest, DocValuesMultiTest, TestFaceting, ZkControllerTest, MinimalSchemaTest, SimpleFacetsTest, UpdateParamsTest, TestStressUserVersions, BadCopyFieldTest, TestIntervalFaceting, SolrTestCaseJ4Test, MergeStrategyTest, CollectionsAPIAsyncDistributedZkTest, RegexBoostProcessorTest, StandardRequestHandlerTest, UnloadDistributedZkTest, TestStressVersions, TestDFRSimilarityFactory, OverseerCollectionProcessorTest, TestCollationKeyRangeQueries, TestLMJelinekMercerSimilarityFactory, TestFastOutputStream, TestNRTOpen, TestFieldTypeResource, PingRequestHandlerTest, TestSchemaResource, PluginInfoTest, IndexBasedSpellCheckerTest, TestManagedResource, SpellCheckCollatorTest, HdfsChaosMonkeySafeLeaderTest, BadIndexSchemaTest, TestSort, SpellCheckComponentTest, ZkCLITest, QueryEqualityTest, MultiThreadedOCPTest] [junit4] Completed on J0 in 59.22s, 1 test, 1 failure <<< FAILURES! [...truncated 695 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:474: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:447: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:496: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923: There were test failures: 411 suites, 1707 tests, 1 error, 1 failure, 50 ignored (8 assumptions) Total time: 237 minutes 39 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #586 Archived 3 artifacts Archive block size is 32768 Received 0 blocks and 460095004 bytes Compression is 0.0% Took 1 min 18 sec Recording test results Email was triggered for: Failure Sending email for trigger: Failure
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org