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 2014/07/15 08:36:33 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0_20-ea-b21) -
Build # 4189 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4189/
Java: 32bit/jdk1.8.0_20-ea-b21 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testDoubleAssignment
Error Message:
Illegal state, was:null expected:recoveringclusterState:live nodes:[node1] collections:{}
Stack Trace:
java.lang.AssertionError: Illegal state, was:null expected:recoveringclusterState:live nodes:[node1] collections:{}
at __randomizedtesting.SeedInfo.seed([B7E6D1FA759057FC:F7A382113ECD42AA]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.OverseerTest.verifyStatus(OverseerTest.java:579)
at org.apache.solr.cloud.OverseerTest.testDoubleAssignment(OverseerTest.java:805)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11106 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.OverseerTest-B7E6D1FA759057FC-001\init-core-data-001
[junit4] 2> 2146052 T5694 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 2146053 T5694 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2146054 T5694 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2146056 T5694 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 2146058 T5694 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2146059 T5695 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2146148 T5694 oasc.ZkTestServer.run start zk server on port:54579
[junit4] 2> 2146150 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2146155 T5701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1921f63 name:ZooKeeperConnection Watcher:127.0.0.1:54579/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2146156 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2146157 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2146159 T5703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@197cb06 name:ZooKeeperConnection Watcher:127.0.0.1:54579 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2146160 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2146163 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2146165 T5705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15da009 name:ZooKeeperConnection Watcher:127.0.0.1:54579 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2146166 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2146166 T5694 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2146171 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2146175 T5694 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2146177 T5694 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2146179 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2146183 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2146187 T5707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45e977 name:ZooKeeperConnection Watcher:127.0.0.1:54579/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2146187 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2146188 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2146191 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2146204 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2146212 T5709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d791db name:ZooKeeperConnection Watcher:127.0.0.1:54579/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2146212 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2146213 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2146215 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2146219 T5694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54579_solr
[junit4] 2> 2146219 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2146222 T5694 oasc.Overseer.start Overseer (id=92104429392429060-127.0.0.1:54579_solr-n_0000000000) starting
[junit4] 2> 2146224 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2146226 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2146230 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2146233 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2146236 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2146239 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2146250 T5710 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2146255 T5710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2146256 T5710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2146256 T5710 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 2146256 T5710 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2146260 T5709 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2146262 T5701 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> 2146263 T5707 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> 2146270 T5711 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2146694 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2146705 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2146711 T5709 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2146711 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2146712 T5710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2146716 T5694 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54579 54579
[junit4] 2> 2148041 T5710 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /clusterstate.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ClusterState.load(ClusterState.java:239)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:445)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:242)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:234)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2148711 T5710 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54579_solr
[junit4] 2> 2148046 T5711 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2148712 T5695 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54579 54579
[junit4] 2> 2148712 T5712 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 2148714 T5694 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 2148718 T5694 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 2148719 T5694 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2148720 T5713 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2148809 T5694 oasc.ZkTestServer.run start zk server on port:54597
[junit4] 2> 2148811 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148815 T5719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d1ac9c name:ZooKeeperConnection Watcher:127.0.0.1:54597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148815 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148816 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148818 T5721 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d409e7 name:ZooKeeperConnection Watcher:127.0.0.1:54597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148818 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148820 T5714 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387d9e960001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2148821 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148822 T5723 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1434d5b name:ZooKeeperConnection Watcher:127.0.0.1:54597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148822 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148823 T5694 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2148827 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2148827 T5714 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387d9e960002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2148829 T5694 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2148832 T5694 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2148834 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2148838 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2148843 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148845 T5725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb5561 name:ZooKeeperConnection Watcher:127.0.0.1:54597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148845 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148846 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2148847 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2148852 T5694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54597_solr
[junit4] 2> 2148852 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2148854 T5694 oasc.Overseer.start Overseer (id=92104429567082499-127.0.0.1:54597_solr-n_0000000000) starting
[junit4] 2> 2148856 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2148860 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2148864 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2148867 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2148872 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2148878 T5727 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2148880 T5726 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2148881 T5726 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2148882 T5726 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> 2148883 T5719 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> 2148886 T5726 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> 2148887 T5719 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> 2148890 T5726 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2148891 T5726 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2148892 T5726 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> 2148895 T5725 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2148986 T5719 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> 2149059 T5694 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54597 54597
[junit4] 2> 2150653 T5727 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2151032 T5713 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54597 54597
[junit4] 2> 2151032 T5694 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 2151035 T5694 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 2151036 T5694 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2151037 T5728 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2151041 T5726 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54597_solr
[junit4] 2> 2151042 T5733 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 2151117 T5694 oasc.ZkTestServer.run start zk server on port:54612
[junit4] 2> 2151119 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151122 T5735 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b00750 name:ZooKeeperConnection Watcher:127.0.0.1:54612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151122 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151125 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151127 T5737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c6a3a8 name:ZooKeeperConnection Watcher:127.0.0.1:54612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151127 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151127 T5694 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2151143 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151144 T5739 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68ad4c name:ZooKeeperConnection Watcher:127.0.0.1:54612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151144 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151144 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2151147 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151155 T5741 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eeffb7 name:ZooKeeperConnection Watcher:127.0.0.1:54612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151155 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151156 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2151158 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2151162 T5694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54612_solr
[junit4] 2> 2151162 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2151165 T5694 oasc.Overseer.start Overseer (id=92104429718732803-127.0.0.1:54612_solr-n_0000000000) starting
[junit4] 2> 2151166 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2151169 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2151173 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2151176 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2151180 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2151183 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2151192 T5743 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2151192 T5694 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2151193 T5742 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2151194 T5694 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2151196 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2151199 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151201 T5745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@125fc7d name:ZooKeeperConnection Watcher:127.0.0.1:54612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151201 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151201 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2151204 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 2151209 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151211 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2151211 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2151211 T5742 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2151211 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2151214 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151214 T5739 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> 2151215 T5745 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> 2151608 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2151619 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2151625 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151626 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151626 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2151631 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2151631 T5742 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2151631 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2151633 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151715 T5739 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> 2151716 T5745 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> 2152025 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2152034 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 2152040 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152040 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152040 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152042 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152042 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2152048 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2152048 T5742 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2152048 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2152051 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152133 T5739 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> 2152133 T5745 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> 2152441 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2152449 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2152454 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152454 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152454 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152455 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2152455 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152459 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2152460 T5742 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2152460 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2152462 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152546 T5739 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> 2152546 T5745 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> 2152855 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2152863 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152863 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152863 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152866 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2152867 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2152867 T5742 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2152867 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2152869 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2152951 T5739 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> 2152951 T5745 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> 2153262 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2153271 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2153271 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2153271 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2153273 T5742 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2153274 T5742 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2153274 T5742 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2153274 T5742 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2153276 T5741 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2153358 T5739 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> 2153359 T5745 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> 2153670 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2153678 T5729 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387da7a00002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2153694 T5729 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387da7a00004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2153696 T5729 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387da7a00003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2153697 T5694 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54612 54612
[junit4] 2> 2154385 T5743 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2154875 T5745 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2155492 T5745 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2155493 T5745 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2155493 T5745 oasc.LeaderElector$ElectionWatcher.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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2155496 T5728 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54612 54612
[junit4] 2> 2155496 T5694 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 2155499 T5742 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54612_solr
[junit4] 2> 2155500 T5694 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 2155500 T5694 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2155503 T5747 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2155503 T5746 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 2155583 T5694 oasc.ZkTestServer.run start zk server on port:54630
[junit4] 2> 2155584 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2155587 T5753 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1621ed9 name:ZooKeeperConnection Watcher:127.0.0.1:54630 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2155587 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2155590 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2155593 T5755 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@765fc5 name:ZooKeeperConnection Watcher:127.0.0.1:54630 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2155593 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2155593 T5694 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2155596 T5748 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387db9110001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2155597 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2155600 T5757 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ae98a2 name:ZooKeeperConnection Watcher:127.0.0.1:54630/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2155600 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2155600 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2155602 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2155604 T5759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@df9937 name:ZooKeeperConnection Watcher:127.0.0.1:54630/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2155605 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2155605 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2155606 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2155608 T5694 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54630_solr
[junit4] 2> 2155608 T5694 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2155611 T5694 oasc.Overseer.start Overseer (id=92104430011351043-127.0.0.1:54630_solr-n_0000000000) starting
[junit4] 2> 2155612 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2155614 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2155616 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2155618 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2155621 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2155626 T5694 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2155630 T5694 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2155630 T5761 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2155632 T5760 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2155634 T5694 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2155636 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2155640 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2155641 T5763 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f4cb63 name:ZooKeeperConnection Watcher:127.0.0.1:54630/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2155641 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2155643 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2155644 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 2155650 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2155652 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2155653 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2155653 T5760 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2155653 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2155657 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2155657 T5757 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> 2155658 T5763 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> 2156048 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2156058 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2156062 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156064 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156064 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2156068 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2156068 T5760 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2156068 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2156070 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156153 T5757 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> 2156153 T5763 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> 2156462 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2156469 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 2156475 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156475 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156475 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156476 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156476 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2156484 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2156484 T5760 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2156484 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2156487 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156568 T5757 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> 2156569 T5763 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> 2156874 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2156882 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2156887 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156887 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156887 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156888 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2156891 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2156972 T5757 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> 2156973 T5763 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> 2157012 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157012 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157012 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157014 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157014 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2157015 T5760 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2157021 T5760 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 2157023 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157024 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2157024 T5760 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 2157024 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2157027 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157110 T5757 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> 2157110 T5763 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> 2157415 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 2157424 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 2157429 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157429 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157429 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157431 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157431 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2157435 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2157435 T5760 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2157435 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2157437 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157519 T5757 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> 2157519 T5763 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> 2157829 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 2157840 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 2157846 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157847 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157847 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157848 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157849 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2157854 T5760 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2157854 T5760 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2157854 T5760 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2157857 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2157939 T5763 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> 2157939 T5757 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> 2158247 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 2158255 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 2158260 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2158260 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2158261 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2158262 T5760 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2158265 T5759 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2158348 T5763 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> 2158348 T5757 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> 2158382 T5748 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387db9110002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2158385 T5748 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387db9110004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2158388 T5694 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54630 54630
[junit4] 2> 2158825 T5761 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2159499 T5763 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2160043 T5747 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54630 54630
[junit4] 2> 2160045 T5694 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 2160046 T5760 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54630_solr
[junit4] 2> 2160047 T5764 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 2160049 T5694 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2160050 T5694 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2160051 T5765 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2160123 T5694 oasc.ZkTestServer.run start zk server on port:54648
[junit4] 2> 2160125 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160129 T5771 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@166336f name:ZooKeeperConnection Watcher:127.0.0.1:54648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160129 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160130 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160131 T5773 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cfd4a9 name:ZooKeeperConnection Watcher:127.0.0.1:54648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160131 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160133 T5766 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387dcad60001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2160134 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160136 T5775 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a7ff06 name:ZooKeeperConnection Watcher:127.0.0.1:54648 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160136 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160136 T5694 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2160139 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2160143 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160144 T5776 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160146 T5778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9390c2 name:ZooKeeperConnection Watcher:127.0.0.1:54648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160146 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160146 T5780 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18d284c name:ZooKeeperConnection Watcher:127.0.0.1:54648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160147 T5776 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160147 T5694 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2160148 T5776 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2160149 T5694 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2160151 T5776 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2160151 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2160155 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2160157 T5776 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54648_solr
[junit4] 2> 2160157 T5776 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2160161 T5694 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2160162 T5776 oasc.Overseer.start Overseer (id=92104430309474308-127.0.0.1:54648_solr-n_0000000000) starting
[junit4] 2> 2160165 T5776 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2160169 T5776 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2160173 T5776 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2160176 T5776 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2160179 T5776 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2160185 T5776 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2160186 T5782 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2160187 T5781 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:99)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:173)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:394)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:145)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2160188 T5776 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160190 T5784 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14add0d name:ZooKeeperConnection Watcher:127.0.0.1:54648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160190 T5776 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160190 T5782 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92104430309474308-127.0.0.1:54648_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2160190 T5782 oasc.SolrException.log ERROR :org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/collection-queue-work
[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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:99)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.getTailId(DistributedQueue.java:483)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:241)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2160190 T5782 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[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:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:256)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2160195 T5776 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54648_solr
[junit4] 2> 2160195 T5776 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2160198 T5776 oasc.Overseer.start Overseer (id=92104430309474309-127.0.0.1:54648_solr-n_0000000001) starting
[junit4] 2> 2160215 T5786 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2160216 T5785 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2160220 T5785 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2160220 T5785 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> 2160220 T5785 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2160220 T5785 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2160223 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160224 T5778 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> 2160522 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2160531 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2160537 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160538 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2160538 T5785 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2160538 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160541 T5785 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> 2160542 T5785 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2160544 T5694 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2160544 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160546 T5788 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7826f4 name:ZooKeeperConnection Watcher:127.0.0.1:54648/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2160546 T5694 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2160546 T5694 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2160548 T5694 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2160553 T5694 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2160553 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160554 T5785 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> 2160554 T5785 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2160557 T5784 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2160560 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2160632 T5778 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> 2160632 T5788 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live node
[...truncated too long message...]
ateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2225759 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2225813 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2225867 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2225921 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2225978 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226031 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226088 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226144 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226197 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226251 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226307 T5694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2226360 T5694 oasc.OverseerTest.waitForCollections WARN Timeout waiting for collections: [collection1] state:live nodes:[node1] collections:{}
[junit4] 2> 2231999 T6053 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387e02ab0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2232002 T6053 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147387e02ab0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2232005 T5694 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54930 54930
[junit4] 2> 2233935 T6068 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2234556 T6052 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54930 54930
[junit4] 2> 2234559 T5694 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 2234560 T6067 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54930_solr
[junit4] 2> 2234560 T6069 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testDoubleAssignment -Dtests.seed=B7E6D1FA759057FC -Dtests.slow=true -Dtests.locale=ja_JP_JP_#u-ca-japanese -Dtests.timezone=GMT0 -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 60.2s | OverseerTest.testDoubleAssignment <<<
[junit4] > Throwable #1: java.lang.AssertionError: Illegal state, was:null expected:recoveringclusterState:live nodes:[node1] collections:{}
[junit4] > at __randomizedtesting.SeedInfo.seed([B7E6D1FA759057FC:F7A382113ECD42AA]:0)
[junit4] > at org.apache.solr.cloud.OverseerTest.verifyStatus(OverseerTest.java:579)
[junit4] > at org.apache.solr.cloud.OverseerTest.testDoubleAssignment(OverseerTest.java:805)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2237965 T5694 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\temp\solr.cloud.OverseerTest-B7E6D1FA759057FC-001
[junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ja_JP_JP_#u-ca-japanese, timezone=GMT0
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=2,threads=1,free=47644376,total=281223168
[junit4] 2> NOTE: All tests run in this JVM: [TestArbitraryIndexDir, TestBinaryField, TestPseudoReturnFields, TestFileDictionaryLookup, TestCharFilters, StressHdfsTest, TestHashPartitioner, ShowFileRequestHandlerTest, TestTrie, TestTolerantSearch, SuggesterWFSTTest, TestManagedSchemaFieldResource, TestFieldResource, LeaderElectionTest, EchoParamsTest, ZkControllerTest, TestRemoteStreaming, TestJmxIntegration, CustomCollectionTest, SpellCheckComponentTest, HighlighterMaxOffsetTest, RAMDirectoryFactoryTest, TestDynamicFieldCollectionResource, TestPerFieldSimilarity, TestDefaultSimilarityFactory, RangeFacetTest, TestQueryUtils, DocumentAnalysisRequestHandlerTest, TestQuerySenderListener, TestMultiCoreConfBootstrap, SolrCmdDistributorTest, BlockDirectoryTest, TestMergePolicyConfig, DeleteInactiveReplicaTest, OpenExchangeRatesOrgProviderTest, CollectionsAPIAsyncDistributedZkTest, TestLazyCores, DocValuesMultiTest, TestDistribDocBasedVersion, ShardRoutingTest, SOLR749Test, TestSweetSpotSimilarityFactory, DistributedSuggestComponentTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestManagedResource, SolrCoreTest, TestSolrXmlPersistence, TestQuerySenderNoQuery, SolrRequestParserTest, HighlighterTest, SortByFunctionTest, TestSolrXMLSerializer, TestRecoveryHdfs, PluginInfoTest, TestManagedSchema, RecoveryZkTest, NotRequiredUniqueKeyTest, TestManagedSynonymFilterFactory, TestCloudManagedSchemaConcurrent, TestDistributedGrouping, TestFoldingMultitermQuery, ExternalFileFieldSortTest, SolrTestCaseJ4Test, TestLRUCache, TestRealTimeGet, TestCloudInspectUtil, LoggingHandlerTest, DistributedExpandComponentTest, ZkCLITest, TestOverriddenPrefixQueryForCustomFieldType, TestOrdValues, TestExtendedDismaxParser, UUIDFieldTest, CopyFieldTest, TestReplicationHandler, TestPartialUpdateDeduplication, TestSchemaResource, LukeRequestHandlerTest, HardAutoCommitTest, TestXIncludeConfig, TestSolr4Spatial, TestAnalyzedSuggestions, TestPostingsSolrHighlighter, PrimitiveFieldTypeTest, NoCacheHeaderTest, CoreMergeIndexesAdminHandlerTest, HdfsDirectoryTest, DirectUpdateHandlerTest, NumericFieldsTest, BadIndexSchemaTest, RollingRestartTest, TermVectorComponentDistributedTest, TestFastWriter, TestRandomMergePolicy, XmlUpdateRequestHandlerTest, TestReplicationHandlerBackup, HdfsLockFactoryTest, MergeStrategyTest, DistributedSpellCheckComponentTest, TestFreeTextSuggestions, SearchHandlerTest, TestWordDelimiterFilterFactory, EnumFieldTest, PreAnalyzedFieldTest, AsyncMigrateRouteKeyTest, TestBadConfig, QueryEqualityTest, TestIBSimilarityFactory, UpdateParamsTest, SuggesterTest, TestDFRSimilarityFactory, TestRandomFaceting, JSONWriterTest, TestCursorMarkWithoutUniqueKey, HdfsRecoveryZkTest, TestComplexPhraseQParserPlugin, TestSolrIndexConfig, TestJoin, TestLFUCache, TestDocBasedVersionConstraints, HdfsSyncSliceTest, TestSolrQueryParser, PingRequestHandlerTest, OverseerTest]
[junit4] Completed in 91.97s, 9 tests, 1 failure <<< FAILURES!
[...truncated 917 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1298: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:922: There were test failures: 418 suites, 1710 tests, 1 failure, 43 ignored (22 assumptions)
Total time: 139 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.8.0_20-ea-b21 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any