You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/20 13:41:18 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_60-ea-b15) -
Build # 4049 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4049/
Java: 64bit/jdk1.7.0_60-ea-b15 -XX:-UseCompressedOops -XX:+UseG1GC
2 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([F3FACE40DADD0DD5:F7F241B3C878E2F4]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 46 more
FAILED: org.apache.solr.cloud.ReplicationFactorTest.testDistribSearch
Error Message:
Expected rf=3 as partitions to replicas have been healed, but got 2
Stack Trace:
java.lang.AssertionError: Expected rf=3 as partitions to replicas have been healed, but got 2
at __randomizedtesting.SeedInfo.seed([F3FACE40DADD0DD5:721C4058AD826DE9]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.ReplicationFactorTest.testRf3(ReplicationFactorTest.java:238)
at org.apache.solr.cloud.ReplicationFactorTest.doTest(ReplicationFactorTest.java:135)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
at sun.reflect.GeneratedMethodAccessor39.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10987 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-F3FACE40DADD0DD5-001\init-core-data-001
[junit4] 2> 1806674 T6665 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1806676 T6665 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1806676 T6665 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1806683 T6665 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 1806686 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1806687 T6666 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1806838 T6665 oasc.ZkTestServer.run start zk server on port:59479
[junit4] 2> 1806841 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1806853 T6672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d390411 name:ZooKeeperConnection Watcher:127.0.0.1:59479 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1806853 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1806863 T6667 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949425f0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1806866 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1806871 T6674 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59ef7e49 name:ZooKeeperConnection Watcher:127.0.0.1:59479 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1806872 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1806872 T6665 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1806881 T6667 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949425f0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1806884 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1806893 T6676 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a30d1c1 name:ZooKeeperConnection Watcher:127.0.0.1:59479/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1806893 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1806894 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1806901 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1806906 T6678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e2549b3 name:ZooKeeperConnection Watcher:127.0.0.1:59479/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1806906 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1806909 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1806916 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1806934 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59479_solr
[junit4] 2> 1806935 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1806941 T6665 oasc.Overseer.start Overseer (id=91788644844503043-127.0.0.1:59479_solr-n_0000000000) starting
[junit4] 2> 1806945 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1806961 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1806970 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1806979 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1806988 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1806998 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1807016 T6680 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1807016 T6665 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1807021 T6679 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1807023 T6665 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1807027 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1807038 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1807042 T6682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d315dc0 name:ZooKeeperConnection Watcher:127.0.0.1:59479/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1807042 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1807045 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1807054 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1807071 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1807076 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1807077 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1807077 T6679 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1807077 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1807084 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1807087 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1807089 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1807821 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1807845 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1807859 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1807872 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1807874 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1807886 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1807886 T6679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1807886 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1807896 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808053 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1808054 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1808624 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1808646 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1808662 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808662 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808662 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808668 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808669 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1808680 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1808680 T6679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1808681 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1808688 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1808845 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1808845 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1809419 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1809440 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1809454 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1809454 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1809454 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1809459 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1809460 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1809468 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1809469 T6679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1809469 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1809475 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1809635 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1809635 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1810210 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1810228 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1810229 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1810229 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1810232 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1810234 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1810234 T6679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1810234 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1810240 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1810396 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1810396 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1810979 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1811019 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1811020 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1811020 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1811025 T6679 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1811026 T6679 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1811026 T6679 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1811026 T6679 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1811034 T6678 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1811189 T6682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1811190 T6676 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1811770 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1811792 T6667 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949425f0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1811807 T6667 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949425f0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1811807 T6665 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59479 59479
[junit4] 2> 1813029 T6680 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 1814050 T6682 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1815192 T6666 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59479 59479
[junit4] 2> 1815192 T6682 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1815196 T6665 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 1815198 T6682 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1815201 T6679 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59479_solr
[junit4] 2> 1815204 T6683 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1815213 T6665 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1815216 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1815217 T6684 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1815368 T6665 oasc.ZkTestServer.run start zk server on port:59497
[junit4] 2> 1815371 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1815378 T6690 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b6301e8 name:ZooKeeperConnection Watcher:127.0.0.1:59497/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1815380 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1815383 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1815387 T6692 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6eda587a name:ZooKeeperConnection Watcher:127.0.0.1:59497 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1815387 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1815393 T6685 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146194963af0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1815396 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1815399 T6694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c7edcd2 name:ZooKeeperConnection Watcher:127.0.0.1:59497 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1815400 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1815400 T6665 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1815407 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1815416 T6665 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1815422 T6665 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1815426 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1815435 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1815440 T6696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20e237fa name:ZooKeeperConnection Watcher:127.0.0.1:59497/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1815441 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1815443 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1815448 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1815460 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59497_solr
[junit4] 2> 1815462 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1815467 T6665 oasc.Overseer.start Overseer (id=91788645403394051-127.0.0.1:59497_solr-n_0000000000) starting
[junit4] 2> 1815473 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1815482 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1815491 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1815500 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1815508 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1815519 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1815535 T6698 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1815541 T6697 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1815541 T6665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1815548 T6697 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1815551 T6697 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1815551 T6697 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1815558 T6696 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1815561 T6690 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1815623 T6665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1815627 T6696 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1815632 T6697 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1815633 T6697 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 1815633 T6697 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1815633 T6697 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1815643 T6696 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1815800 T6690 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1815860 T6685 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146194963af0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1815863 T6685 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146194963af0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1815869 T6665 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59497 59497
[junit4] 2> 1818542 T6698 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 1819253 T6684 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59497 59497
[junit4] 2> 1819257 T6665 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 1819258 T6697 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59497_solr
[junit4] 2> 1819261 T6699 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1819273 T6665 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 1819276 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1819277 T6700 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1819430 T6665 oasc.ZkTestServer.run start zk server on port:59512
[junit4] 2> 1819431 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1819440 T6706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7214b4a7 name:ZooKeeperConnection Watcher:127.0.0.1:59512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1819441 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1819449 T6701 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949738c0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1819452 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1819458 T6708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55c866e name:ZooKeeperConnection Watcher:127.0.0.1:59512 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1819458 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1819459 T6665 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1819466 T6701 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949738c0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1819469 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1819474 T6710 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5677c57b name:ZooKeeperConnection Watcher:127.0.0.1:59512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1819474 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1819474 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1819480 T6665 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1819485 T6665 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1819490 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1819499 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1819502 T6712 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28ebb45b name:ZooKeeperConnection Watcher:127.0.0.1:59512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1819503 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1819504 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1819510 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1819521 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1819523 T6714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48a4fa4e name:ZooKeeperConnection Watcher:127.0.0.1:59512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1819525 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1819526 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1819531 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1819543 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59512_solr
[junit4] 2> 1819543 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1819548 T6665 oasc.Overseer.start Overseer (id=91788645669535748-127.0.0.1:59512_solr-n_0000000000) starting
[junit4] 2> 1819553 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1819560 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1819567 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1819575 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1819582 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1819592 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1819606 T6716 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1819607 T6715 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1821113 T6714 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1821117 T6715 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1821119 T6715 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1821119 T6715 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1821119 T6715 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1821126 T6714 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1821129 T6712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1821130 T6710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1821863 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1821885 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1821898 T6714 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1821898 T6665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1821901 T6715 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1821905 T6714 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1821905 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1821911 T6715 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1821913 T6715 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1821917 T6714 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1822071 T6710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1822072 T6712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1822153 T6701 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949738c0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1822580 T6716 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 1823522 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1823537 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1823539 T6718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c088c0f name:ZooKeeperConnection Watcher:127.0.0.1:59512/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1823541 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1823541 T6715 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59512_solr
[junit4] 2> 1823544 T6719 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1823548 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59512_solr
[junit4] 2> 1823550 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1823555 T6665 oasc.Overseer.start Overseer (id=91788645669535749-127.0.0.1:59512_solr-n_0000000001) starting
[junit4] 2> 1823580 T6721 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1823581 T6720 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1823584 T6720 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1823585 T6720 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1823587 T6720 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1823591 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823593 T6712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1823593 T6710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1823670 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823670 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1823672 T6720 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1823686 T6665 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91788645669535747-node1_core1-n_0000000000
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1823687 T6720 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1066)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:346)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1823688 T6712 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1823691 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1823693 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823701 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823704 T6712 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1823705 T6720 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1823712 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823716 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823719 T6720 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1823728 T6718 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1823866 T6710 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1823867 T6712 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1825050 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1826407 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1827763 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1829121 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1830477 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1831834 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1833192 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1834548 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1835895 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1837116 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1838337 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1839561 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1840782 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1842003 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1843224 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1843242 T6665 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59512 59512
[junit4] 2> 1844270 T6721 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 1845980 T6700 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59512 59512
[junit4] 2> 1845983 T6665 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 1845984 T6720 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59512_solr
[junit4] 2> 1845986 T6722 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=F3FACE40DADD0DD5 -Dtests.slow=true -Dtests.locale=es_CO -Dtests.timezone=Pacific/Wake -Dtests.file.encoding=Cp1252
[junit4] ERROR 26.8s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([F3FACE40DADD0DD5:F7F241B3C878E2F4]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > ... 46 more
[junit4] 2> 1846028 T6665 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1846030 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1846031 T6723 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1846153 T6665 oasc.ZkTestServer.run start zk server on port:59533
[junit4] 2> 1846156 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1846180 T6729 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@713e8dbe name:ZooKeeperConnection Watcher:127.0.0.1:59533/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1846181 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1846183 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1846187 T6731 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@448cef7a name:ZooKeeperConnection Watcher:127.0.0.1:59533 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1846187 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1846191 T6724 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949dc0f0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1846193 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1846196 T6733 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@325ccd36 name:ZooKeeperConnection Watcher:127.0.0.1:59533 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1846196 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1846196 T6665 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1846203 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1846204 T6724 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949dc0f0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1846210 T6665 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1846215 T6665 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1846219 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1846227 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1846238 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1846241 T6735 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38c474ca name:ZooKeeperConnection Watcher:127.0.0.1:59533/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1846241 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1846242 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1846247 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1846257 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59533_solr
[junit4] 2> 1846258 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1846263 T6665 oasc.Overseer.start Overseer (id=91788647422951427-127.0.0.1:59533_solr-n_0000000000) starting
[junit4] 2> 1846266 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1846277 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1846285 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1846292 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1846301 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1846318 T6737 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1846327 T6736 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1846328 T6736 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1846329 T6736 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1846333 T6729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1846340 T6736 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1846343 T6729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1846349 T6736 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1846353 T6736 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1846354 T6736 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1846360 T6735 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1846486 T6729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1846570 T6724 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949dc0f0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1846575 T6724 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949dc0f0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1846575 T6665 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59533 59533
[junit4] 2> 1848677 T6737 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 1849179 T6723 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59533 59533
[junit4] 2> 1849181 T6665 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1849182 T6736 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59533_solr
[junit4] 2> 1849184 T6738 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1849189 T6665 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1849193 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1849195 T6739 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1849305 T6665 oasc.ZkTestServer.run start zk server on port:59548
[junit4] 2> 1849307 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1849315 T6745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bbcbda9 name:ZooKeeperConnection Watcher:127.0.0.1:59548/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1849316 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1849330 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1849344 T6747 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31d5b3fd name:ZooKeeperConnection Watcher:127.0.0.1:59548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1849345 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1849371 T6740 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949e8660001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1849373 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1849387 T6749 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ffad13f name:ZooKeeperConnection Watcher:127.0.0.1:59548 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1849388 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1849388 T6665 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1849404 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1849408 T6740 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1461949e8660002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1849423 T6750 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[...truncated too long message...]
cationFactorTest.java:135)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 3727461 T13207 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ReplicationFactorTest-F3FACE40DADD0DD5-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=DefaultSimilarity, locale=in_ID, timezone=Africa/Libreville
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=106923088,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestRemoteStreaming, SignatureUpdateProcessorFactoryTest, ExternalFileFieldSortTest, TestPseudoReturnFields, TestXIncludeConfig, TestExpandComponent, OverseerRolesTest, CursorMarkTest, TestSolrDeletionPolicy1, SpatialFilterTest, DistributedQueryComponentCustomSortTest, TestRandomDVFaceting, QueryFacetTest, SuggesterTest, ModifyConfFileTest, DirectSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, NoFacetTest, ResponseLogComponentTest, TestPerFieldSimilarity, LoggingHandlerTest, PathHierarchyTokenizerFactoryTest, BadComponentTest, MultiThreadedOCPTest, TestSolrXml, TestReloadAndDeleteDocs, TestRandomFaceting, TestCollectionAPI, ClusterStateTest, TestManagedResource, TestReversedWildcardFilterFactory, UpdateParamsTest, ChaosMonkeySafeLeaderTest, CachingDirectoryFactoryTest, TestConfig, DateFieldTest, XmlUpdateRequestHandlerTest, TestPhraseSuggestions, TestCodecSupport, BasicZkTest, TestFreeTextSuggestions, NotRequiredUniqueKeyTest, TestFieldTypeResource, DefaultValueUpdateProcessorTest, TestZkChroot, TestRealTimeGet, ResponseHeaderTest, TestMiniSolrCloudCluster, SpellCheckCollatorTest, WordBreakSolrSpellCheckerTest, SyncSliceTest, HttpPartitionTest, HdfsBasicDistributedZkTest, TestDFRSimilarityFactory, TestBlendedInfixSuggestions, TestSolrIndexConfig, AddBlockUpdateTest, DistributedSuggestComponentTest, SpellPossibilityIteratorTest, CacheHeaderTest, AbstractAnalyticsFacetTest, TestBinaryResponseWriter, TestAtomicUpdateErrorCases, SolrInfoMBeanTest, MergeStrategyTest, RangeFacetTest, TestFunctionQuery, DebugComponentTest, TestQuerySenderNoQuery, HardAutoCommitTest, HdfsCollectionsAPIDistributedZkTest, TestAddFieldRealTimeGet, TestSolrXmlPersistence, DistributedQueryComponentOptimizationTest, TestNonNRTOpen, TestCollationFieldDocValues, TestSimpleQParserPlugin, DistribCursorPagingTest, TestMultiCoreConfBootstrap, TestStressLucene, SliceStateUpdateTest, TestStressUserVersions, BJQParserTest, TestRecoveryHdfs, SolrIndexSplitterTest, TestDefaultSimilarityFactory, DistributedSpellCheckComponentTest, TestCloudInspectUtil, InfoHandlerTest, DirectSolrConnectionTest, TestNRTOpen, TestRangeQuery, SuggesterFSTTest, TestFaceting, DistributedTermsComponentTest, PeerSyncTest, BinaryUpdateRequestHandlerTest, TestImplicitCoreProperties, SolrRequestParserTest, DeleteShardTest, TestBinaryField, TestRestManager, TestDynamicFieldCollectionResource, TestRandomMergePolicy, TestSolrQueryParserResource, TestCharFilters, StandardRequestHandlerTest, TestFileDictionaryLookup, RemoteQueryErrorTest, TestIndexSearcher, TestFastOutputStream, DocExpirationUpdateProcessorFactoryTest, HdfsWriteToMultipleCollectionsTest, HdfsUnloadDistributedZkTest, ZkControllerTest, TestStandardQParsers, SimpleFacetsTest, TestDefaultSearchFieldResource, TestSolrCoreProperties, BasicFunctionalityTest, TestBadConfig, FieldAnalysisRequestHandlerTest, CurrencyFieldOpenExchangeTest, TestLazyCores, DOMUtilTest, TimeZoneUtilsTest, StatsComponentTest, TestSerializedLuceneMatchVersion, TestManagedSchema, ZkCLITest, TestShardHandlerFactory, TestSweetSpotSimilarityFactory, TestTrie, OverseerCollectionProcessorTest, SoftAutoCommitTest, TestSolrQueryParser, TestSearcherReuse, TestSolrQueryParserDefaultOperatorResource, TestRTGBase, SchemaVersionSpecificBehaviorTest, RegexBoostProcessorTest, DistributedQueryElevationComponentTest, TestAnalyzeInfixSuggestions, RecoveryZkTest, TestSchemaNameResource, TestSearchPerf, TestCSVResponseWriter, TestStressRecovery, TestHighlightDedupGrouping, TestDistributedMissingSort, TestComplexPhraseQParserPlugin, SpellingQueryConverterTest, NoCacheHeaderTest, TestDocSet, TestCollapseQParserPlugin, TestDistributedSearch, IndexSchemaTest, TestDocBasedVersionConstraints, TestCoreContainer, TestStressVersions, UpdateRequestProcessorFactoryTest, DocValuesTest, URLClassifyProcessorTest, TermVectorComponentTest, TermVectorComponentDistributedTest, CollectionsAPIDistributedZkTest, TestDistribDocBasedVersion, JSONWriterTest, SOLR749Test, TestOverriddenPrefixQueryForCustomFieldType, EchoParamsTest, AssignTest, QueryElevationComponentTest, XsltUpdateRequestHandlerTest, LegacyHTMLStripCharFilterTest, OverseerTest, FileUtilsTest, TestLMJelinekMercerSimilarityFactory, DeleteReplicaTest, BasicDistributedZkTest, TestDynamicFieldResource, TestGroupingSearch, TestQueryTypes, PluginInfoTest, CurrencyFieldXmlFileTest, TestRecovery, CopyFieldTest, ShardRoutingTest, SuggesterWFSTTest, TestSuggestSpellingConverter, MoreLikeThisHandlerTest, BasicDistributedZk2Test, AsyncMigrateRouteKeyTest, TestModifyConfFiles, TestReplicationHandler, SSLMigrationTest, ChangedSchemaMergeTest, TestLRUCache, LeaderElectionIntegrationTest, UnloadDistributedZkTest, OpenCloseCoreStressTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, LeaderElectionTest, ZkSolrClientTest, ShardRoutingCustomTest, AutoCommitTest, TestDistributedGrouping, TestHashPartitioner, TestStressReorder, TestJoin, TestReload, TestSolr4Spatial, SolrCoreTest, SpellCheckComponentTest, SolrCmdDistributorTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, TestFiltering, DirectUpdateHandlerTest, HighlighterTest, ShowFileRequestHandlerTest, SimplePostToolTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, CoreAdminHandlerTest, TestFoldingMultitermQuery, SuggesterTSTTest, TestCSVLoader, PolyFieldTest, TestUpdate, FieldMutatingUpdateProcessorTest, TestWordDelimiterFilterFactory, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, DocValuesMultiTest, DistanceFunctionTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, TestWriterPerf, DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest, TestOmitPositions, FileBasedSpellCheckerTest, TermsComponentTest, RequestHandlersTest, DocumentBuilderTest, TestValueSourceCache, TestIndexingPerformance, RequiredFieldsTest, TestArbitraryIndexDir, FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestJmxIntegration, TestCollationField, ReturnFieldsTest, MBeansHandlerTest, QueryParsingTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, PingRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, CoreContainerCoreInitFailuresTest, TestLFUCache, HighlighterConfigTest, TestQuerySenderListener, AlternateDirectoryTest, SolrIndexConfigTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, TestLuceneMatchVersion, SynonymTokenizerTest, TestLMDirichletSimilarityFactory, TestIBSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, TestJmxMonitoredMap, ResourceLoaderTest, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, TestFastLRUCache, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, RAMDirectoryFactoryTest, TestSolrJ, TestUtils, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, SystemInfoHandlerTest, UUIDFieldTest, CircularListTest, CursorPagingTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, AbstractAnalyticsStatsTest, ExpressionTest, FieldFacetExtrasTest, FieldFacetTest, FunctionTest, AliasIntegrationTest, CollectionsAPIAsyncDistributedZkTest, ConnectionManagerTest, CustomCollectionTest, DeleteInactiveReplicaTest, DistribDocExpirationUpdateProcessorTest, MigrateRouteKeyTest, OverseerStatusTest, ReplicationFactorTest]
[junit4] Completed in 47.12s, 1 test, 1 failure <<< FAILURES!
[...truncated 195 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 406 suites, 1688 tests, 1 error, 1 failure, 42 ignored (21 assumptions)
Total time: 106 minutes 4 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b15 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure