You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/09/23 14:15:19 UTC
[JENKINS] Lucene-Solr-Tests-5.x-Java7 - Build # 3544 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.x-Java7/3544/
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior
Error Message:
Illegal state, was: down expected:active clusterState:live nodes:[]collections:{c1=DocCollection(c1)={ "shards":{"shard1":{ "state":"active", "range":null, "parent":null, "replicas":{"core_node1":{ "base_url":"http://127.0.0.1/solr", "node_name":"node1", "core":"core1", "roles":"", "state":"down"}}}}, "router":{"name":"implicit"}}, test=LazyCollectionRef(test)}
Stack Trace:
java.lang.AssertionError: Illegal state, was: down expected:active clusterState:live nodes:[]collections:{c1=DocCollection(c1)={
"shards":{"shard1":{
"state":"active",
"range":null,
"parent":null,
"replicas":{"core_node1":{
"base_url":"http://127.0.0.1/solr",
"node_name":"node1",
"core":"core1",
"roles":"",
"state":"down"}}}},
"router":{"name":"implicit"}}, test=LazyCollectionRef(test)}
at __randomizedtesting.SeedInfo.seed([C01D695AE82E3942:A8036AB60ABE630C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.OverseerTest.verifyStatus(OverseerTest.java:601)
at org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior(OverseerTest.java:1261)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1665)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:864)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:900)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:914)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:873)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:775)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:809)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:820)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10167 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerTest_C01D695AE82E3942-001/init-core-data-001
[junit4] 2> 518718 INFO (SUITE-OverseerTest-seed#[C01D695AE82E3942]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 518718 INFO (SUITE-OverseerTest-seed#[C01D695AE82E3942]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 518718 INFO (SUITE-OverseerTest-seed#[C01D695AE82E3942]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 518795 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStateChange
[junit4] 2> 518795 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 518796 INFO (Thread-2250) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 518796 INFO (Thread-2250) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 518896 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer start zk server on port:42612
[junit4] 2> 518896 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 518897 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 518900 INFO (zkCallback-376-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@140a9dea name:ZooKeeperConnection Watcher:127.0.0.1:42612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 518900 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 518900 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 518901 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 518912 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 518917 INFO (zkCallback-377-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7922d5c name:ZooKeeperConnection Watcher:127.0.0.1:42612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 518918 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 518918 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 518922 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x14ffa07e3700001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 518924 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 518930 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 518947 INFO (zkCallback-378-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6bf7ffa3 name:ZooKeeperConnection Watcher:127.0.0.1:42612 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 518947 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 518947 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 518947 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 518966 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 518968 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 518969 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 518970 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 518971 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 518971 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 518973 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 518975 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 518975 INFO (zkCallback-379-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2701c1ed name:ZooKeeperConnection Watcher:127.0.0.1:42612/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 518975 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 518975 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 518976 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 518982 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 518997 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 518998 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 518999 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94569028985552899-127.0.0.1:42612_solr-n_0000000000
[junit4] 2> 518999 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42612_solr
[junit4] 2> 518999 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 519000 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569028985552899-127.0.0.1:42612_solr-n_0000000000) starting
[junit4] 2> 519001 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 519003 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 519004 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 519005 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 519007 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 519009 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 519012 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 519013 INFO (OverseerCollectionConfigSetProcessor-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 519013 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 519013 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 519017 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, 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"} current state version: 0
[junit4] 2> 519018 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator 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> 519018 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 519019 INFO (zkCallback-379-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519019 INFO (zkCallback-376-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519086 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, 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"} current state version: 1
[junit4] 2> 519087 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator 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> 519087 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node1 is already registered
[junit4] 2> 519087 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered
[junit4] 2> 519190 INFO (zkCallback-379-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519190 INFO (zkCallback-376-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519233 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42612 42612
[junit4] 2> 519234 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x14ffa07e3700003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 519442 INFO (Thread-2250) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42612 42612
[junit4] 2> 519443 WARN (Thread-2250) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> 519443 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateChange
[junit4] 2> 519444 INFO (TEST-OverseerTest.testStateChange-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569028985552899-127.0.0.1:42612_solr-n_0000000000) closing
[junit4] 2> 519446 INFO (OverseerStateUpdate-94569028985552899-127.0.0.1:42612_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:42612_solr
[junit4] 2> 519446 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data
[junit4] 2> 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:345)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265)
[junit4] 2> 519450 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPlaceholders
[junit4] 2> 519450 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 519451 INFO (Thread-2251) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 519451 INFO (Thread-2251) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 519551 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer start zk server on port:39497
[junit4] 2> 519551 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 519567 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 519588 INFO (zkCallback-381-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@12b51517 name:ZooKeeperConnection Watcher:127.0.0.1:39497/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 519588 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 519588 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 519588 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 519590 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 519595 INFO (zkCallback-382-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3569b652 name:ZooKeeperConnection Watcher:127.0.0.1:39497 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 519595 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 519595 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 519597 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 519598 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 519599 INFO (zkCallback-383-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@719f6833 name:ZooKeeperConnection Watcher:127.0.0.1:39497 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 519599 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 519599 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 519599 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 519602 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 519604 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 519605 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 519607 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 519608 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 519609 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 519611 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 519612 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 519615 INFO (zkCallback-384-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5fb8009e name:ZooKeeperConnection Watcher:127.0.0.1:39497/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 519615 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 519615 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 519626 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 519633 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 519636 INFO (zkCallback-381-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519641 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 519646 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 519646 INFO (zkCallback-384-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 519668 INFO (zkCallback-385-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@632ef8c0 name:ZooKeeperConnection Watcher:127.0.0.1:39497/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 519669 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 519669 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 519670 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 519671 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 519673 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 519674 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 519674 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94569029028413444-127.0.0.1:39497_solr-n_0000000000
[junit4] 2> 519675 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39497_solr
[junit4] 2> 519675 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 519676 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569029028413444-127.0.0.1:39497_solr-n_0000000000) starting
[junit4] 2> 519677 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 519681 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 519683 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 519684 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 519685 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 519687 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 519689 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 519710 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 519713 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 519714 INFO (OverseerCollectionConfigSetProcessor-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 519733 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"} current state version: 0
[junit4] 2> 519738 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 519738 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 519738 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard9
[junit4] 2> 519740 INFO (zkCallback-384-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 519740 INFO (zkCallback-381-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 519740 INFO (zkCallback-385-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520233 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard9/election
[junit4] 2> 520235 INFO (zkCallback-385-thread-2) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating...
[junit4] 2> 520235 INFO (zkCallback-381-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating...
[junit4] 2> 520236 INFO (zkCallback-384-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating...
[junit4] 2> 520239 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard9/election/94569029028413443-node1_core1-n_0000000000
[junit4] 2> 520240 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard9
[junit4] 2> 520242 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node
[junit4] 2> 520256 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard9",
[junit4] 2> "collection":"collection1",
[junit4] 2> "base_url":"http://node1/solr/",
[junit4] 2> "core":"core1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 520260 INFO (zkCallback-381-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520260 INFO (zkCallback-384-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520262 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x14ffa07e5fe0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 520263 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39497 39497
[junit4] 2> 520507 INFO (Thread-2251) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39497 39497
[junit4] 2> 520507 WARN (Thread-2251) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 520508 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPlaceholders
[junit4] 2> 520508 INFO (TEST-OverseerTest.testPlaceholders-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569029028413444-127.0.0.1:39497_solr-n_0000000000) closing
[junit4] 2> 520508 INFO (OverseerStateUpdate-94569029028413444-127.0.0.1:39497_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39497_solr
[junit4] 2> 520508 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data
[junit4] 2> 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:345)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265)
[junit4] 2> 520517 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testShardAssignmentBigger
[junit4] 2> 520517 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 520530 INFO (Thread-2252) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 520531 INFO (Thread-2252) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 520622 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer start zk server on port:47227
[junit4] 2> 520622 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520634 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520642 INFO (zkCallback-387-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7bfa6fd2 name:ZooKeeperConnection Watcher:127.0.0.1:47227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520642 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520643 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520652 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520663 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520666 INFO (zkCallback-388-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@70b4e1bf name:ZooKeeperConnection Watcher:127.0.0.1:47227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520666 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520667 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520667 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 520685 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520690 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520690 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@32406730 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520690 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520690 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520691 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 520698 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 520699 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 520701 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 520702 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 520703 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520704 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520706 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@8abadc7 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520706 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520706 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520706 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 520708 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 520715 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 520718 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 520724 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94569029099388931-127.0.0.1:47227_solr-n_0000000000
[junit4] 2> 520724 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:47227_solr
[junit4] 2> 520724 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 520725 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569029099388931-127.0.0.1:47227_solr-n_0000000000) starting
[junit4] 2> 520726 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 520730 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 520732 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 520733 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 520734 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 520736 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 520738 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 520739 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520739 INFO (OverseerCollectionConfigSetProcessor-94569029099388931-127.0.0.1:47227_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 520740 INFO (OverseerStateUpdate-94569029099388931-127.0.0.1:47227_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 520740 INFO (OverseerStateUpdate-94569029099388931-127.0.0.1:47227_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520758 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520765 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520774 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1099366d name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520774 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520774 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520782 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520787 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node0
[junit4] 2> 520788 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 520788 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 520788 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0)
[junit4] 2> 520789 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520805 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520831 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7b869098 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520831 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520832 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520833 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520835 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1
[junit4] 2> 520836 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520836 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520837 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520836 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 520837 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520838 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520842 INFO (zkCallback-394-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@54cea5d5 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520842 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520842 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520844 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520846 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node2
[junit4] 2> 520847 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 520847 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 520847 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 520848 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520848 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520850 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6ae95716 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520850 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520850 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520847 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 520852 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520852 INFO (zkCallback-394-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 520854 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node3
[junit4] 2> 520855 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520855 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520855 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520855 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520856 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520858 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520858 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520858 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 520906 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6c551e6e name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520906 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520906 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520914 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520916 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node4
[junit4] 2> 520918 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520918 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 520919 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520921 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520928 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4d0caa2 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520929 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520929 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520931 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520933 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node5
[junit4] 2> 520934 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520934 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520934 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520934 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520934 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520935 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520936 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520937 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4eaa058 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520937 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520937 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520938 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520938 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520937 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4] 2> 520942 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520944 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node6
[junit4] 2> 520945 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520945 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520945 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520945 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520945 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520945 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520946 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520946 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520948 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4] 2> 520949 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520954 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520956 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6432e3dd name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520956 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520956 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520958 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 520961 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node7
[junit4] 2> 520962 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520962 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520963 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520964 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 520966 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 520973 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4] 2> 520976 INFO (zkCallback-400-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@34559e38 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 520977 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 520977 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 520985 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 521020 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node8
[junit4] 2> 521021 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521022 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521022 INFO (zkCallback-400-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521021 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4] 2> 521023 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 521024 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 521027 INFO (zkCallback-401-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@37957c46 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 521027 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 521027 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 521029 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 521038 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node9
[junit4] 2> 521040 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521040 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521041 INFO (zkCallback-401-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521042 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521045 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521045 INFO (zkCallback-400-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 9)
[junit4] 2> 521057 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 521060 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 521069 INFO (zkCallback-402-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@63c6e8bd name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 521070 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 521070 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 521090 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 521096 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node10
[junit4] 2> 521097 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521097 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521097 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-400-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-401-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521098 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521099 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 521100 INFO (zkCallback-402-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 10)
[junit4] 2> 521126 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 521132 INFO (zkCallback-403-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2db56123 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 521132 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 521132 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 521134 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 521135 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node11
[junit4] 2> 521136 INFO (zkCallback-399-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521136 INFO (zkCallback-401-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-398-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-396-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-400-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-395-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-397-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-394-thread-2) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-402-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521137 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521142 INFO (zkCallback-403-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 11)
[junit4] 2> 521142 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 521147 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 521155 INFO (zkCallback-404-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4221c6b0 name:ZooKeeperConnection Watcher:127.0.0.1:47227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 521155 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 521155 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 521157 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 521158 INFO (TEST-OverseerTest.testShardAssignmentBigger-seed#[C01D695AE82E3942]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node12
[junit4] 2> 521160 INFO (zkCallback-392-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-401-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-403-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-393-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-389-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-390-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 12)
[junit4] 2> 521160 INFO (zkCallback-397-thread-1) [ ] o.a.s.c
[...truncated too long message...]
he.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:214)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:261)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> 573685 ERROR (TEST-OverseerTest.testShardAssignment-seed#[C01D695AE82E3942]-EventThread) [ ] o.a.z.ClientCnxn Error while calling watcher
[junit4] 2> java.util.concurrent.RejectedExecutionException: Task org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1@32c61968 rejected from org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@aa0d59b[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 10]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:214)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:261)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2> 575184 WARN (zkCallback-489-thread-1) [ ] o.a.s.c.LeaderElector
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:328)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:325)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:325)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:58)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:388)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:264)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:231)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 575187 INFO (TEST-OverseerTest.testShardAssignment-seed#[C01D695AE82E3942]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:54612 54612
[junit4] 2> 575389 INFO (Thread-2261) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:54612 54612
[junit4] 2> 575390 WARN (Thread-2261) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 575390 INFO (TEST-OverseerTest.testShardAssignment-seed#[C01D695AE82E3942]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testShardAssignment
[junit4] 2> 575390 INFO (TEST-OverseerTest.testShardAssignment-seed#[C01D695AE82E3942]) [ ] o.a.s.c.Overseer Overseer (id=94569032370094083-127.0.0.1:54612_solr-n_0000000000) closing
[junit4] 2> 575392 INFO (OverseerStateUpdate-94569032370094083-127.0.0.1:54612_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:54612_solr
[junit4] 2> 575408 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data
[junit4] 2> 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:345)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265)
[junit4] 2> 578392 INFO (SUITE-OverseerTest-seed#[C01D695AE82E3942]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerTest_C01D695AE82E3942-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene53): {}, docValues:{}, sim=DefaultSimilarity, locale=es_CL, timezone=US/Arizona
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_72 (64-bit)/cpus=4,threads=1,free=234651168,total=452984832
[junit4] 2> NOTE: All tests run in this JVM: [TestCoreDiscovery, CursorMarkTest, SampleTest, CurrencyFieldXmlFileTest, AddBlockUpdateTest, TestElisionMultitermQuery, NoCacheHeaderTest, SuggesterTest, PreAnalyzedUpdateProcessorTest, TestDownShardTolerantSearch, DebugComponentTest, PluginInfoTest, HdfsBasicDistributedZkTest, QueryParsingTest, DirectUpdateHandlerTest, TestDynamicFieldCollectionResource, TestXIncludeConfig, TestStressRecovery, ZkStateWriterTest, DistributedExpandComponentTest, LukeRequestHandlerTest, TestWriterPerf, TestClassNameShortening, TestSolrQueryParserResource, SuggesterTSTTest, TestReRankQParserPlugin, TestSearchPerf, DistributedQueryComponentCustomSortTest, SpatialHeatmapFacetsTest, TestReload, TestPerFieldSimilarity, HdfsDirectoryTest, HdfsLockFactoryTest, TestDistributedMissingSort, TestFuzzyAnalyzedSuggestions, TestSimpleTrackingShardHandler, TestIndexingPerformance, StatelessScriptUpdateProcessorFactoryTest, SecurityConfHandlerTest, BasicDistributedZk2Test, SmileWriterTest, CollectionReloadTest, FieldAnalysisRequestHandlerTest, HdfsWriteToMultipleCollectionsTest, HardAutoCommitTest, HdfsDirectoryFactoryTest, RequestHandlersTest, EnumFieldTest, DistributedFacetPivotLongTailTest, TestMinMaxOnMultiValuedField, TestDefaultSimilarityFactory, SpatialRPTFieldTypeTest, FullSolrCloudDistribCmdsTest, TestJmxIntegration, TestSystemIdResolver, TestAddFieldRealTimeGet, TestAnalyzeInfixSuggestions, BadComponentTest, TestSmileRequest, TestCollapseQParserPlugin, FieldMutatingUpdateProcessorTest, SuggesterWFSTTest, ShowFileRequestHandlerTest, TestDistribIDF, OverseerTest]
[junit4] Completed [174/539] on J2 in 59.72s, 12 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 1156 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:785: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:729: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/common-build.xml:524: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1452: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1006: There were test failures: 539 suites (7 ignored), 2128 tests, 1 failure, 46 ignored (34 assumptions) [seed: C01D695AE82E3942]
Total time: 59 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-5.x-Java7 #3543
Archived 4 artifacts
Archive block size is 32768
Received 0 blocks and 300736377 bytes
Compression is 0.0%
Took 54 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure