You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/30 23:01:41 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/ibm-j9-jdk7) - Build # 8427
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8427/
Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
2 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([214625DD4F0CFD35:254EAA2E5DA91214]:0)
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$10.execute(SolrZkClient.java:424)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
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:70)
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:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
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 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:70)
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:358)
at java.lang.Thread.run(Thread.java:780)
REGRESSION: org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection
Error Message:
expected:<1> but was:<3>
Stack Trace:
java.lang.AssertionError: expected:<1> but was:<3>
at __randomizedtesting.SeedInfo.seed([214625DD4F0CFD35:7A76DE154C4B5E49]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.checkNumDocs(SignatureUpdateProcessorFactoryTest.java:71)
at org.apache.solr.update.processor.SignatureUpdateProcessorFactoryTest.testDupeDetection(SignatureUpdateProcessorFactoryTest.java:119)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
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:70)
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:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
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 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:70)
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:358)
at java.lang.Thread.run(Thread.java:780)
Build Log:
[...truncated 10477 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 415908 T1055 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1385848547081
[junit4] 2> 415909 T1055 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 415913 T1055 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 415914 T1055 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 415936 T1056 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 416015 T1055 oasc.ZkTestServer.run start zk server on port:40748
[junit4] 2> 416016 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416099 T1062 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9e4ade36 name:ZooKeeperConnection Watcher:127.0.0.1:40748/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416099 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416101 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416115 T1064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@960fa058 name:ZooKeeperConnection Watcher:127.0.0.1:40748 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416116 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416119 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416141 T1066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ff110c9 name:ZooKeeperConnection Watcher:127.0.0.1:40748 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416141 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416142 T1055 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 416146 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 416150 T1055 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 416155 T1055 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 416157 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 416162 T1055 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 416168 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416193 T1068 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36094eab name:ZooKeeperConnection Watcher:127.0.0.1:40748/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416193 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416194 T1055 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 416199 T1055 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 416201 T1055 oasc.Overseer.start Overseer (id=90822970383400963-127.0.0.1:40748_solr-n_0000000000) starting
[junit4] 2> 416204 T1055 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 416209 T1055 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 416222 T1069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416225 T1069 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 416228 T1069 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> 416230 T1070 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 416230 T1062 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> 416241 T1069 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> 416242 T1062 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> 416245 T1069 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 416247 T1069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416248 T1069 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> 416251 T1068 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416253 T1062 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> 416317 T1055 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40748 40748
[junit4] 2> 416385 T1055 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 416395 T1055 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 416400 T1055 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 416416 T1071 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 416502 T1055 oasc.ZkTestServer.run start zk server on port:52306
[junit4] 2> 416503 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416508 T1077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fa026c8 name:ZooKeeperConnection Watcher:127.0.0.1:52306/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416509 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416510 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416523 T1079 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e11eafb name:ZooKeeperConnection Watcher:127.0.0.1:52306 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416524 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416556 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416564 T1081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c212893b name:ZooKeeperConnection Watcher:127.0.0.1:52306 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416565 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416565 T1055 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 416569 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 416574 T1055 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 416584 T1055 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 416590 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 416604 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416616 T1083 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b921d3 name:ZooKeeperConnection Watcher:127.0.0.1:52306/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416616 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416624 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 416633 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 416637 T1083 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 416637 T1077 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 416638 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416656 T1085 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9de4ce7f name:ZooKeeperConnection Watcher:127.0.0.1:52306/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416656 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416658 T1055 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 416681 T1055 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 416687 T1055 oasc.Overseer.start Overseer (id=90822970414989316-127.0.0.1:52306_solr-n_0000000000) starting
[junit4] 2> 416693 T1055 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 416703 T1055 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 416711 T1055 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 416718 T1086 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 416736 T1087 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 417719 T1085 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 417720 T1086 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 417721 T1086 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> 417721 T1086 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 417722 T1086 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 417725 T1085 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 417726 T1077 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> 417726 T1083 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> 418219 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 418229 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 418235 T1085 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 418235 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 418237 T1086 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 418240 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 418240 T1085 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 418243 T1086 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> 418244 T1086 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 418248 T1085 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 418352 T1083 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> 418354 T1077 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> 419411 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 419417 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 419436 T1089 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77d7e518 name:ZooKeeperConnection Watcher:127.0.0.1:52306/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 419437 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 419440 T1055 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 419445 T1055 oasc.Overseer.start Overseer (id=90822970414989317-127.0.0.1:52306_solr-n_0000000001) starting
[junit4] 2> 419460 T1091 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 419482 T1090 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 419493 T1090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 419495 T1090 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> 419495 T1090 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 419497 T1089 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419498 T1083 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> 419500 T1077 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> 419556 T1089 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419556 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 419558 T1090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 419562 T1055 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/90822970414989315-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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:613)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[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:70)
[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:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[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 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:70)
[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:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 419565 T1090 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:169)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:166)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:650)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:645)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:875)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:224)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:185)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 419565 T1083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 419566 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 419569 T1089 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419573 T1089 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419577 T1083 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 419577 T1077 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 419577 T1083 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[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.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:201)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:198)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:409)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 419578 T1083 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 419577 T1090 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 419579 T1090 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:235)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:232)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:186)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 419578 T1072 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x142ab02a9080005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 419581 T1055 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52306 52306
[junit4] 2> 419759 T1055 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=214625DD4F0CFD35 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=Pacific/Easter -Dtests.file.encoding=UTF-8
[junit4] ERROR 3.38s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at __randomizedtesting.SeedInfo.seed([214625DD4F0CFD35:254EAA2E5DA91214]:0)
[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$10.execute(SolrZkClient.java:424)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:421)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:378)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:365)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:102)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4] 2> 419778 T1055 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 419778 T1055 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 419784 T1092 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 419879 T1055 oasc.ZkTestServer.run start zk server on port:56113
[junit4] 2> 419881 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 419903 T1098 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cbc98df0 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 419904 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 419905 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 419907 T1100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fc0a94ef name:ZooKeeperConnection Watcher:127.0.0.1:56113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 419908 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 419951 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 419962 T1102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d89b7ce9 name:ZooKeeperConnection Watcher:127.0.0.1:56113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 419963 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 419963 T1055 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 419967 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 419974 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 420000 T1103 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 420002 T1105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb1d588e name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 420002 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 420004 T1055 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 420006 T1055 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 420009 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 420012 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 420015 T1105 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 420016 T1055 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 420017 T1107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b68fbd93 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 420019 T1103 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 420020 T1103 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 420029 T1103 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 420031 T1103 oasc.Overseer.start Overseer (id=90822970635911172-127.0.0.1:56113_solr-n_0000000000) starting
[junit4] 2> 420034 T1103 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 420037 T1103 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 420040 T1103 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 420042 T1103 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 420051 T1108 oasc.Overseer$ClusterStateUpdater.amILeader 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.amILeader(Overseer.java:392)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:91)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 420052 T1108 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90822970635911172-127.0.0.1:56113_solr-n_0000000000) am no longer a leader.
[junit4] 2> 420052 T1108 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 420053 T1108 oasc.Overseer$ClusterStateUpdater.amILeader 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.amILeader(Overseer.java:392)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:151)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 420053 T1108 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90822970635911172-127.0.0.1:56113_solr-n_0000000000) am no longer a leader.
[junit4] 2> 420060 T1109 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 420060 T1109 oasc.OverseerCollectionProcessor.amILeader 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:203)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:155)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 420061 T1109 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=90822970635911172-127.0.0.1:56113_solr-n_0000000000) am no longer a leader.
[junit4] 2> 420061 T1109 oasc.OverseerCollectionProcessor.amILeader 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:269)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:266)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:203)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:162)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 420061 T1111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f22fe17 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 420062 T1109 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=90822970635911172-127.0.0.1:56113_solr-n_0000000000) am no longer a leader.
[junit4] 2> 420062 T1103 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 420065 T1103 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 420067 T1103 oasc.Overseer.start Overseer (id=90822970635911173-127.0.0.1:56113_solr-n_0000000001) starting
[junit4] 2> 420079 T1112 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 420088 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420089 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 420090 T1112 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 420090 T1112 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 420094 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420095 T1105 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> 420096 T1113 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 420521 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 420529 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 420536 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420541 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420541 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 420541 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420546 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 420546 T1112 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 420550 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420550 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 420553 T1115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f9423b0d name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 420553 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 420555 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 420561 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 420564 T1105 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 420565 T1115 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 420567 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 420567 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420569 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 420570 T1112 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 420572 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420574 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420675 T1105 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 420675 T1115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 420777 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420782 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420782 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420783 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420784 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420785 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 420786 T1112 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 420786 T1112 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 420789 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420891 T1105 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 420892 T1115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421282 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 421290 T1105 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421293 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421295 T1115 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421296 T1115 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 421304 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421304 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421304 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421306 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421309 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421415 T1115 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> 421500 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421502 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 421508 T1117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8132712a name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 421511 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 421514 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 421520 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 421524 T1115 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 421525 T1117 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 421529 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421529 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 421529 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421530 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421532 T1112 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421532 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 421533 T1112 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421536 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421547 T1115 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421550 T1117 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421552 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421553 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 421557 T1112 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 421557 T1112 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421558 T1117 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 421560 T1111 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421574 T1103 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 421576 T1103 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 421585 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 421589 T1119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c8b2140 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 421590 T1103 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 421591 T1121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b37f157b name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 421592 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 421594 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 421597 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 421605 T1117 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 421605 T1103 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 421608 T1121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 421610 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 421614 T1103 oasc.Overseer.start Overseer (id=90822970635911177-127.0.0.1:56113_solr-n_0000000002) starting
[junit4] 2> 421624 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421636 T1122 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421637 T1122 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 421638 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 421638 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421640 T1123 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 421640 T1117 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421641 T1121 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421647 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 421649 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421651 T1117 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421652 T1121 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421655 T1122 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 421657 T1122 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421662 T1112 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:193)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 421663 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421665 T1121 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421665 T1117 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421670 T1122 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421671 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 421671 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421675 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421778 T1117 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421778 T1121 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 421828 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421831 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421831 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421832 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421832 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 421834 T1122 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421835 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 421835 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 421838 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421840 T1121 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421840 T1117 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 421842 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 421842 T1121 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 421849 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421853 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 421955 T1121 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> 422044 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422046 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 422060 T1125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5002a8a5 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 422060 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 422063 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 422070 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 422074 T1125 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 422074 T1121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 422077 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422078 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422077 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 422078 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422080 T1122 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422081 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 422081 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422086 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422089 T1125 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 422089 T1121 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 422092 T1125 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 422093 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422093 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 422096 T1122 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 422096 T1122 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422101 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422107 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422111 T1055 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 422111 T1119 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422120 T1127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33f4200e name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 422120 T1055 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 422123 T1055 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 422127 T1055 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 422130 T1127 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 422131 T1103 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 422132 T1125 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 422133 T1103 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 422137 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 422144 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422148 T1129 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51818a12 name:ZooKeeperConnection Watcher:127.0.0.1:56113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 422149 T1103 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 422152 T1103 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 422155 T1103 oasc.Overseer.start Overseer (id=90822970635911180-127.0.0.1:56113_solr-n_0000000003) starting
[junit4] 2> 422161 T1131 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 422163 T1130 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422164 T1130 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 422165 T1130 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 422165 T1130 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422166 T1127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422166 T1125 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422171 T1130 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 422172 T1130 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422173 T1125 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422173 T1127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422176 T1127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422177 T1125 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422178 T1130 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 422180 T1130 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422182 T1130 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 422182 T1130 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422185 T1129 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422186 T1127 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422187 T1125 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 422213 T1122 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:193)
[junit4] 2> at java.lang.Thread.run(Thread.java:780)
[junit4] 2>
[junit4] 2> 422345 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422350 T1129 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422350 T1055 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 422354 T1130 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422355 T1130 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 422356 T1130 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 422359 T1129 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 422362 T1125 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 422362 T1055 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 422362 T1125 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 422362 T1127 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 422363 T1125 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.co
[...truncated too long message...]
enSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 674191 T2813 C1348 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@612069e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a28151c; maxCacheMB=0.4052734375 maxMergeSizeMB=0.171875))),segFN=segments_y,generation=34}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@612069e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a28151c; maxCacheMB=0.4052734375 maxMergeSizeMB=0.171875))),segFN=segments_z,generation=35}
[junit4] 2> 674191 T2813 C1348 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 35
[junit4] 2> 674192 T2813 C1348 oass.SolrIndexSearcher.<init> Opening Searcher@946d4c5a main
[junit4] 2> 674192 T2813 C1348 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 674194 T2815 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@946d4c5a main{StandardDirectoryReader(segments_z:137:nrt)}
[junit4] 2> 674195 T2813 C1348 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
[junit4] 2> 674199 T2813 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 674200 T2813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@612069e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a28151c; maxCacheMB=0.4052734375 maxMergeSizeMB=0.171875))),segFN=segments_z,generation=35}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@612069e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a28151c; maxCacheMB=0.4052734375 maxMergeSizeMB=0.171875))),segFN=segments_10,generation=36}
[junit4] 2> 674201 T2813 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 36
[junit4] 2> 674202 T2813 oass.SolrIndexSearcher.<init> Opening Searcher@946437d8 main
[junit4] 2> 674202 T2813 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 674204 T2815 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@946437d8 main{StandardDirectoryReader(segments_10:139:nrt _16(4.7):C2)}
[junit4] 2> 674205 T2813 oas.SolrTestCaseJ4.tearDown ###Ending testNonIndexedSignatureField
[junit4] 2> 674206 T2813 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 674207 T2813 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=680408749
[junit4] 2> 674207 T2813 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@24b444b3
[junit4] 2> 674224 T2813 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=42,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=253,cumulative_deletesById=0,cumulative_deletesByQuery=6,cumulative_errors=0}
[junit4] 2> 674225 T2813 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 674225 T2813 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 674226 T2813 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 674226 T2813 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 674227 T2813 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 674227 T2813 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366;done=false>>]
[junit4] 2> 674227 T2813 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366
[junit4] 2> 674228 T2813 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366/index;done=false>>]
[junit4] 2> 674228 T2813 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-SignatureUpdateProcessorFactoryTest-1385848803366/index
[junit4] 2> NOTE: test params are: codec=Lucene46: {signatureField=Pulsing41(freqCutoff=13 minBlockSize=16 maxBlockSize=73), id=PostingsFormat(name=Direct), ints_is=Pulsing41(freqCutoff=6 minBlockSize=16 maxBlockSize=73), v_t=PostingsFormat(name=Direct), name=PostingsFormat(name=Direct), weight=PostingsFormat(name=NestedPulsing)}, docValues:{}, sim=DefaultSimilarity, locale=en, timezone=Pacific/Tongatapu
[junit4] 2> NOTE: Linux 3.8.0-33-generic amd64/IBM Corporation 1.7.0 (64-bit)/cpus=8,threads=1,free=182396456,total=285671424
[junit4] 2> NOTE: All tests run in this JVM: [HdfsBasicDistributedZk2Test, SuggesterFSTTest, TestSolrQueryParserDefaultOperatorResource, TestPostingsSolrHighlighter, CircularListTest, ModifyConfFileTest, TestRemoteStreaming, DOMUtilTest, TestElisionMultitermQuery, TestFieldCollectionResource, AutoCommitTest, TestDocBasedVersionConstraints, DistributedTermsComponentTest, TestNRTOpen, TestDocumentBuilder, FieldMutatingUpdateProcessorTest, CSVRequestHandlerTest, TestDynamicFieldResource, HdfsSyncSliceTest, UpdateParamsTest, ResourceLoaderTest, TestBM25SimilarityFactory, ReturnFieldsTest, SuggestComponentTest, StatelessScriptUpdateProcessorFactoryTest, TestCoreContainer, SampleTest, TestClassNameShortening, SOLR749Test, DeleteReplicaTest, TestReloadAndDeleteDocs, TestWriterPerf, TestDocSet, DateMathParserTest, TestConfig, ZkCLITest, TestSchemaVersionResource, TestSimpleQParserPlugin, TestLRUCache, TestMergePolicyConfig, UpdateRequestProcessorFactoryTest, SchemaVersionSpecificBehaviorTest, PolyFieldTest, SuggesterTest, CopyFieldTest, BlockDirectoryTest, TestLMJelinekMercerSimilarityFactory, FastVectorHighlighterTest, TestCollapseQParserPlugin, TestRealTimeGet, SimpleFacetsTest, AddSchemaFieldsUpdateProcessorFactoryTest, SliceStateUpdateTest, TestCopyFieldCollectionResource, TestJmxMonitoredMap, DistributedSpellCheckComponentTest, TestManagedSchemaFieldResource, TestExtendedDismaxParser, TestUniqueKeyFieldResource, ZkControllerTest, TestLFUCache, TestRandomDVFaceting, SolrInfoMBeanTest, MBeansHandlerTest, PreAnalyzedUpdateProcessorTest, ShowFileRequestHandlerTest, BasicFunctionalityTest, TestSuggestSpellingConverter, QueryEqualityTest, RecoveryZkTest, TestBadConfig, TestValueSourceCache, FileBasedSpellCheckerTest, TestFunctionQuery, SpatialFilterTest, TestJoin, SliceStateTest, SolrXmlInZkTest, StressHdfsTest, BadCopyFieldTest, TestPerFieldSimilarity, UnloadDistributedZkTest, LoggingHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, OverseerTest, ShardRoutingTest, TestReplicationHandler, ClusterStateUpdateTest, LeaderElectionTest, ZkSolrClientTest, ShardRoutingCustomTest, TestDistributedSearch, TestDistributedGrouping, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestStressReorder, TestStressVersions, TestSolr4Spatial, StatsComponentTest, SpellCheckComponentTest, QueryElevationComponentTest, PeerSyncTest, BadIndexSchemaTest, TestSort, TestLazyCores, OverseerCollectionProcessorTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest]
[junit4] Completed on J0 in 2.05s, 6 tests, 1 failure <<< FAILURES!
[...truncated 430 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:426: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:419: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1279: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:912: There were test failures: 349 suites, 1516 tests, 1 error, 1 failure, 68 ignored (6 assumptions)
Total time: 35 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure