lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0) - Build # 9974 - Failure!
Date Thu, 03 Apr 2014 06:15:38 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9974/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC

4 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.OverseerTest

Error Message:
ERROR: SolrZkClient opens=118 closes=117

Stack Trace:
java.lang.AssertionError: ERROR: SolrZkClient opens=118 closes=117
	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:484)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:198)
	at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
	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:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:789)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
	at java.lang.Thread.run(Thread.java:744)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.OverseerTest

Error Message:
2 threads leaked from SUITE scope at org.apache.solr.cloud.OverseerTest:     1) Thread[id=1526, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-EventThread, state=WAITING, group=TGRP-OverseerTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)    2) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.OverseerTest: 
   1) Thread[id=1526, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-EventThread, state=WAITING, group=TGRP-OverseerTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
   2) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.OverseerTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)


REGRESSION:  org.apache.solr.cloud.OverseerTest.testShardAssignmentBigger

Error Message:
KeeperErrorCode = NodeExists for /live_nodes/node29

Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /live_nodes/node29
	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8:6C83DE055995029B]:0)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
	at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:350)
	at org.apache.solr.cloud.OverseerTest$MockZKController.<init>(OverseerTest.java:86)
	at org.apache.solr.cloud.OverseerTest.testShardAssignmentBigger(OverseerTest.java:367)
	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:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10822 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1396505434529
   [junit4]   2> 328950 T1358 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 328950 T1358 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 328950 T1358 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 328952 T1358 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
   [junit4]   2> 328953 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 328953 T1359 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 329053 T1358 oasc.ZkTestServer.run start zk server on port:42158
   [junit4]   2> 329054 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329129 T1365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@233fbba6 name:ZooKeeperConnection Watcher:127.0.0.1:42158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329129 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329130 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329132 T1367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b1b861c name:ZooKeeperConnection Watcher:127.0.0.1:42158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329132 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329134 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329135 T1369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16e20ae8 name:ZooKeeperConnection Watcher:127.0.0.1:42158 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329135 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329136 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 329138 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 329140 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 329141 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 329142 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 329143 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329144 T1371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6805c2d4 name:ZooKeeperConnection Watcher:127.0.0.1:42158/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329144 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329145 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 329146 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 329148 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42158_solr
   [junit4]   2> 329148 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 329149 T1358 oasc.Overseer.start Overseer (id=91521380157685763-127.0.0.1:42158_solr-n_0000000000) starting
   [junit4]   2> 329150 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 329152 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 329153 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 329154 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 329157 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 329160 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 329163 T1373 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 329163 T1373 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 329164 T1372 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 329164 T1358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 329165 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 329165 T1372 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> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"recovering"}
   [junit4]   2> 329165 T1372 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 329166 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 329167 T1365 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> 329215 T1358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 329217 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 329218 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 329219 T1372 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> 	  "collection":"collection1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "roles":"",
   [junit4]   2> 	  "state":"active"}
   [junit4]   2> 329219 T1372 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
   [junit4]   2> 329219 T1372 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 329221 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 329323 T1365 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> 329371 T1358 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42158 42158
   [junit4]   2> 329499 T1359 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42158 42158
   [junit4]   2> 329500 T1358 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
   [junit4]   2> 329501 T1374 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 329503 T1358 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
   [junit4]   2> 329504 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 329504 T1375 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 329604 T1358 oasc.ZkTestServer.run start zk server on port:50994
   [junit4]   2> 329605 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329610 T1381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36b9b6f9 name:ZooKeeperConnection Watcher:127.0.0.1:50994 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329610 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329631 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329633 T1383 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71d5ed54 name:ZooKeeperConnection Watcher:127.0.0.1:50994 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329634 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329634 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 329638 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329640 T1385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77660ccc name:ZooKeeperConnection Watcher:127.0.0.1:50994/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329640 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329641 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 329644 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 329648 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 329651 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 329655 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329657 T1387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31b36396 name:ZooKeeperConnection Watcher:127.0.0.1:50994/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329658 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329659 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 329662 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 329665 T1385 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 329666 T1387 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 329666 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 329668 T1389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ac61527 name:ZooKeeperConnection Watcher:127.0.0.1:50994/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 329668 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 329669 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 329670 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 329672 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50994_solr
   [junit4]   2> 329672 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 329673 T1358 oasc.Overseer.start Overseer (id=91521380193927172-127.0.0.1:50994_solr-n_0000000000) starting
   [junit4]   2> 329674 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 329676 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 329677 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 329679 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 329680 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 329682 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 329684 T1391 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 329685 T1391 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 329685 T1390 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 330686 T1389 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 330688 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 330688 T1390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 330688 T1390 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 330688 T1390 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 330690 T1389 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 330691 T1385 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> 330691 T1387 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> 331187 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 331197 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 331202 T1389 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 331203 T1358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 331204 T1390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 331208 T1389 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 331208 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 331209 T1390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 331210 T1390 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 331212 T1389 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 331315 T1385 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> 331315 T1387 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> 332370 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 332373 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 332375 T1393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1427ee66 name:ZooKeeperConnection Watcher:127.0.0.1:50994/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 332375 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 332378 T1394 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   2> 332382 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50994_solr
   [junit4]   2> 332382 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 332384 T1358 oasc.Overseer.start Overseer (id=91521380193927173-127.0.0.1:50994_solr-n_0000000001) starting
   [junit4]   2> 332393 T1395 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 332394 T1395 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 332394 T1395 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 332395 T1395 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 332400 T1396 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 332400 T1393 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 332401 T1396 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 332401 T1387 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> 332401 T1385 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> 332469 T1393 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 332469 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 332470 T1395 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 332498 T1387 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 332500 T1387 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 332501 T1387 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
   [junit4]   2> 332516 T1393 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 332620 T1385 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> 332620 T1387 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> 333121 T1385 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 333121 T1387 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 333124 T1358 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50994 50994
   [junit4]   2> 333227 T1375 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50994 50994
   [junit4]   2> 333229 T1358 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 333232 T1397 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   2> 333234 T1358 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
   [junit4]   2> 333235 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 333235 T1398 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 333335 T1358 oasc.ZkTestServer.run start zk server on port:53611
   [junit4]   2> 333336 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333347 T1404 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79e5e67b name:ZooKeeperConnection Watcher:127.0.0.1:53611/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333347 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333348 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333350 T1406 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f0ab4d name:ZooKeeperConnection Watcher:127.0.0.1:53611 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333351 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333365 T1399 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452635ea650001, 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:744)
   [junit4]   2> 
   [junit4]   2> 333372 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333376 T1408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@288f218b name:ZooKeeperConnection Watcher:127.0.0.1:53611 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333377 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333377 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 333380 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 333380 T1399 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452635ea650002, 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:744)
   [junit4]   2> 
   [junit4]   2> 333382 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 333385 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 333386 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 333388 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333390 T1410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7fba5648 name:ZooKeeperConnection Watcher:127.0.0.1:53611/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333390 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333392 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 333394 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 333395 T1404 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 333396 T1410 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 333403 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333405 T1412 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@293aa1fa name:ZooKeeperConnection Watcher:127.0.0.1:53611/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333405 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333406 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 333408 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 333412 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53611_solr
   [junit4]   2> 333412 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 333413 T1358 oasc.Overseer.start Overseer (id=91521380438573060-127.0.0.1:53611_solr-n_0000000000) starting
   [junit4]   2> 333415 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 333417 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 333420 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 333422 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 333423 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 333427 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 333433 T1414 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 333434 T1413 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 333434 T1414 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 333437 T1413 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 333437 T1413 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 333437 T1413 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 333437 T1413 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 333441 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 333441 T1410 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> 333442 T1404 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> 333935 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 333960 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 333963 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 333964 T1358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 333964 T1413 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 333972 T1404 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 333972 T1410 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 333973 T1399 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452635ea650003, 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:744)
   [junit4]   2> 
   [junit4]   2> 333974 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 333974 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 333979 T1416 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f16dd53 name:ZooKeeperConnection Watcher:127.0.0.1:53611/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 333979 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 333980 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 333982 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 333983 T1404 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 333984 T1416 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 333985 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 333985 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 333986 T1413 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "node_name":"node1",
   [junit4]   2> 	  "core":"core1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "base_url":"http://node1/solr/"}
   [junit4]   2> 333986 T1413 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 334002 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334010 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 334013 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334017 T1412 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334121 T1404 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> 334121 T1416 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> 334122 T1358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 334129 T1404 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 334129 T1416 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 334131 T1358 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53611 53611
   [junit4]   2> 334233 T1398 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53611 53611
   [junit4]   2> 334234 T1358 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
   [junit4]   2> 334235 T1417 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 334238 T1358 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
   [junit4]   2> 334239 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 334245 T1418 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 334339 T1358 oasc.ZkTestServer.run start zk server on port:36583
   [junit4]   2> 334340 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 334355 T1424 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53e133c5 name:ZooKeeperConnection Watcher:127.0.0.1:36583 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 334356 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 334383 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 334390 T1426 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fa87d32 name:ZooKeeperConnection Watcher:127.0.0.1:36583 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 334390 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 334391 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 334397 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 334398 T1428 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36cdc1d1 name:ZooKeeperConnection Watcher:127.0.0.1:36583/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 334398 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 334398 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 334400 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 334401 T1430 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@69443b71 name:ZooKeeperConnection Watcher:127.0.0.1:36583/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 334402 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 334403 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 334404 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 334407 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36583_solr
   [junit4]   2> 334407 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 334409 T1358 oasc.Overseer.start Overseer (id=91521380504829955-127.0.0.1:36583_solr-n_0000000000) starting
   [junit4]   2> 334410 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 334412 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 334413 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 334415 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 334417 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 334418 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 334421 T1432 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 334421 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 334421 T1432 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 334422 T1431 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 334423 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 334424 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 334425 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 334427 T1434 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33614287 name:ZooKeeperConnection Watcher:127.0.0.1:36583/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 334428 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 334428 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 334429 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
   [junit4]   2> 334431 T1428 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 334431 T1434 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 334432 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334433 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 334433 T1431 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> 334433 T1431 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 334433 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 334435 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334436 T1428 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> 334436 T1434 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> 334932 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 334939 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 334942 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334943 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 334944 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 334947 T1431 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> 334948 T1431 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 334948 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 334949 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335050 T1428 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> 335050 T1434 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> 335444 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 335449 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 335451 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335452 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335452 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335452 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 335453 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335454 T1431 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> 335454 T1431 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 335454 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 335455 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335559 T1428 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> 335559 T1434 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> 335953 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 335957 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 335960 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335960 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335960 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 335961 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 335962 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336063 T1428 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> 336063 T1434 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> 336112 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336112 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336113 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336114 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336114 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 336115 T1431 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> 336116 T1431 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> 336117 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336118 T1431 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> 336118 T1431 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
   [junit4]   2> 336118 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 336119 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336221 T1434 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> 336221 T1428 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> 336615 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
   [junit4]   2> 336620 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
   [junit4]   2> 336623 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336623 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336623 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336624 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336624 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 336627 T1431 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> 336627 T1431 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 336627 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 336630 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 336732 T1428 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> 336732 T1434 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> 337124 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
   [junit4]   2> 337129 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
   [junit4]   2> 337132 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337132 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337132 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337133 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337133 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 337135 T1431 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> 337135 T1431 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 337136 T1431 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 337137 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337239 T1428 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> 337240 T1434 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> 337633 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
   [junit4]   2> 337638 T1358 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
   [junit4]   2> 337641 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337641 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337641 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337642 T1431 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 337643 T1430 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 337745 T1428 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> 337745 T1434 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> 337794 T1434 oascc.ZkStateReader$3.process Updating live nodes... (0)
   [junit4]   2> 337795 T1358 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36583 36583
   [junit4]   2> 337922 T1418 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36583 36583
   [junit4]   2> 337923 T1358 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
   [junit4]   2> 337924 T1435 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 337927 T1358 oas.SolrTestCaseJ4.setUp ###Starting testReplay
   [junit4]   2> 337927 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 337927 T1436 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 338027 T1358 oasc.ZkTestServer.run start zk server on port:48574
   [junit4]   2> 338028 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338031 T1442 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7576945 name:ZooKeeperConnection Watcher:127.0.0.1:48574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338031 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338032 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338034 T1444 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f00456d name:ZooKeeperConnection Watcher:127.0.0.1:48574 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338034 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338052 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338054 T1446 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76cc5370 name:ZooKeeperConnection Watcher:127.0.0.1:48574 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338054 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338054 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 338056 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 338057 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 338058 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 338059 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338060 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 338062 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338063 T1448 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ef988c5 name:ZooKeeperConnection Watcher:127.0.0.1:48574/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338063 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338064 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 338065 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 338070 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48574_solr
   [junit4]   2> 338070 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 338071 T1358 oasc.Overseer.start Overseer (id=91521380746067971-127.0.0.1:48574_solr-n_0000000000) starting
   [junit4]   2> 338072 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 338074 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 338075 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 338077 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 338078 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 338082 T1450 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 338083 T1450 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 338084 T1449 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 338084 T1449 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
   [junit4]   2> 338085 T1449 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> 338087 T1442 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> 338091 T1449 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> 338092 T1442 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> 338094 T1449 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 338095 T1449 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 338095 T1449 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> 338098 T1448 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 338099 T1442 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> 338186 T1358 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:48574 48574
   [junit4]   2> 338515 T1436 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:48574 48574
   [junit4]   2> 338517 T1358 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
   [junit4]   2> 338519 T1451 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:301)
   [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:290)
   [junit4]   2> 
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 338523 T1358 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignmentBigger
   [junit4]   2> 338523 T1358 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 338524 T1452 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 338624 T1358 oasc.ZkTestServer.run start zk server on port:35055
   [junit4]   2> 338624 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338627 T1458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7258cd1e name:ZooKeeperConnection Watcher:127.0.0.1:35055 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338627 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338647 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338649 T1460 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fbec515 name:ZooKeeperConnection Watcher:127.0.0.1:35055 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338649 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338649 T1358 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 338652 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338654 T1462 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bfd5641 name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338654 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338655 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 338658 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338660 T1464 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29405c5b name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338660 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338662 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 338665 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 338669 T1358 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:35055_solr
   [junit4]   2> 338670 T1358 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 338672 T1358 oasc.Overseer.start Overseer (id=91521380785586179-127.0.0.1:35055_solr-n_0000000000) starting
   [junit4]   2> 338673 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 338678 T1358 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 338683 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 338686 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 338688 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 338689 T1358 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 338691 T1466 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 338692 T1358 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 338692 T1466 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 338692 T1465 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 338693 T1358 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 338693 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338695 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338696 T1468 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dc44450 name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338696 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338697 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338698 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node0
   [junit4]   2> 338700 T1462 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 338700 T1468 oascc.ZkStateReader$3.process Updating live nodes... (1)
   [junit4]   2> 338700 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338701 T1470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@541bbc90 name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338701 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338702 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338703 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
   [junit4]   2> 338704 T1462 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 338705 T1470 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 338705 T1468 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 338705 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338706 T1472 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1515a70c name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338706 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338707 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338708 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
   [junit4]   2> 338709 T1462 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 338709 T1468 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 338709 T1470 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 338709 T1472 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 338709 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 338710 T1474 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e1c8371 name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 338710 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 338711 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 338712 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node3
   [junit4]   2> 339756 T1455 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1043ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 339758 T1462 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 339758 T1472 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 339758 T1468 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 339758 T1474 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 339758 T1470 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 339758 T1358 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 339760 T1476 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c5b626 name:ZooKeeperConnection Watcher:127.0.0.1:35055/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 339761 T1358 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 339761 T1358 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 339763 T1358 oascc.SolrZkClient.makePath makePath: /live_nodes/node4
   [junit4]   2> 339764 T1468 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339764 T1474 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339765 T1462 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339765 T1470 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339764 T1472 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339765 T1476 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 339766 T1358 oascc.ConnectionManager.waitForConnected Waiting for

[...truncated too long message...]

[junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> 407365 T1525 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]   2> 
   [junit4]   2> 407865 T1525 oazc.StaticHostProvider.next WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]   2> 
   [junit4]   2> 407865 T1525 oaz.ClientCnxn$SendThread.run WARN Session 0x1452635ff140021 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> 408365 T1525 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]   2> 
   [junit4]   2> 408865 T1525 oazc.StaticHostProvider.next WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]   2> 
   [junit4]   2> 408866 T1525 oaz.ClientCnxn$SendThread.run WARN Session 0x1452635ff140021 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> 409365 T1525 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]   2> 
   [junit4]   2> 80916 T1357 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
   [junit4]   2> 	   1) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=zh_TW, timezone=Europe/Tirane
   [junit4]   2> NOTE: Linux 3.8.0-37-generic amd64/Oracle Corporation 1.8.0 (64-bit)/cpus=8,threads=2,free=173224864,total=235405312
   [junit4]   2> NOTE: All tests run in this JVM: [TestCustomSort, LoggingHandlerTest, TestRemoteStreaming, TestStandardQParsers, TestPerFieldSimilarity, TestNonNRTOpen, DistribCursorPagingTest, ReturnFieldsTest, ShardRoutingTest, TestFieldResource, TestRealTimeGet, OverseerStatusTest, TestSort, PrimitiveFieldTypeTest, SolrCoreTest, TestSystemIdResolver, TestPHPSerializedResponseWriter, TestExceedMaxTermLength, SystemInfoHandlerTest, TestCollationFieldDocValues, BasicFunctionalityTest, DistributedTermsComponentTest, ModifyConfFileTest, CopyFieldTest, ExpressionTest, SuggestComponentTest, AnalysisErrorHandlingTest, RangeFacetTest, TestConfig, PreAnalyzedUpdateProcessorTest, TestReloadAndDeleteDocs, SoftAutoCommitTest, SyncSliceTest, SliceStateUpdateTest, BadCopyFieldTest, QueryElevationComponentTest, SolrIndexSplitterTest, TestSuggestSpellingConverter, TestFieldTypeCollectionResource, TestGroupingSearch, DocValuesTest, AssignTest, TestModifyConfFiles, ClusterStateTest, TestSolrIndexConfig, HdfsDirectoryTest, BlockDirectoryTest, SampleTest, DocumentBuilderTest, SimpleFacetsTest, MBeansHandlerTest, SpatialFilterTest, OverseerTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=OverseerTest -Dtests.seed=FF6D207EB3FCFDF8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=zh_TW -Dtests.timezone=Europe/Tirane -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J0 | OverseerTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: ERROR: SolrZkClient opens=118 closes=117
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:484)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:198)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.OverseerTest: 
   [junit4]    >    1) Thread[id=1526, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-EventThread, state=WAITING, group=TGRP-OverseerTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
   [junit4]    >    2) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]
   [junit4]    >         at java.lang.Thread.sleep(Native Method)
   [junit4]    >         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=1525, name=TEST-OverseerTest.testShardAssignmentBigger-seed#[FF6D207EB3FCFDF8]-SendThread(127.0.0.1:35055), state=TIMED_WAITING, group=TGRP-OverseerTest]
   [junit4]    >         at java.lang.Thread.sleep(Native Method)
   [junit4]    >         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([FF6D207EB3FCFDF8]:0)
   [junit4] Completed on J0 in 80.94s, 9 tests, 1 failure, 3 errors <<< FAILURES!

[...truncated 881 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:907: There were test failures: 397 suites, 1674 tests, 3 suite-level errors, 1 error, 1043 ignored (9 assumptions)

Total time: 41 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message