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/08/13 06:25:23 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_65) - Build #
11012 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11012/
Java: 32bit/jdk1.7.0_65 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: 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([6641C8D44BE5DD9F:62494727594032BE]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
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:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
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$11.execute(SolrZkClient.java:457)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
... 47 more
Build Log:
[...truncated 11487 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-6641C8D44BE5DD9F-001/init-core-data-001
[junit4] 2> 1667522 T4468 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 1667522 T4468 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1667522 T4468 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1667525 T4468 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 1667526 T4468 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1667526 T4469 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1667626 T4468 oasc.ZkTestServer.run start zk server on port:57571
[junit4] 2> 1667627 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1667640 T4475 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b61e92 name:ZooKeeperConnection Watcher:127.0.0.1:57571 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1667640 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1667642 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1667643 T4477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ff1df name:ZooKeeperConnection Watcher:127.0.0.1:57571 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1667644 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1667644 T4468 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1667649 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1667650 T4479 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@190ef4e name:ZooKeeperConnection Watcher:127.0.0.1:57571/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1667650 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1667651 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1667654 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1667655 T4481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1929d0f name:ZooKeeperConnection Watcher:127.0.0.1:57571/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1667655 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1667656 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1667659 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1667663 T4468 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57571_solr
[junit4] 2> 1667664 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1667665 T4468 oasc.Overseer.start Overseer (id=92268298564468739-127.0.0.1:57571_solr-n_0000000000) starting
[junit4] 2> 1667667 T4468 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1667669 T4468 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1667672 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1667674 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1667676 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1667678 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1667682 T4483 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1667682 T4468 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1667682 T4482 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1667684 T4468 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1667685 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1667687 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1667688 T4485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aa7de8 name:ZooKeeperConnection Watcher:127.0.0.1:57571/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1667688 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1667689 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1667690 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1667693 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1667694 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1667694 T4482 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> 1667695 T4482 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1667695 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1667697 T4486 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> 1667697 T4487 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> 1668193 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1668199 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1668202 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1668203 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1668205 T4482 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> 1668205 T4482 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1668205 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1668206 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1668207 T4487 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> 1668207 T4486 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> 1668703 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1668708 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1668711 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1668712 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1668714 T4482 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> 1668715 T4482 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1668715 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1668716 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1668717 T4487 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> 1668717 T4486 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> 1669212 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1669216 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1669219 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669220 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1669222 T4482 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> 1669223 T4482 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1669223 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1669224 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669225 T4486 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> 1669225 T4487 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> 1669720 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1669727 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669728 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1669728 T4482 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> 1669729 T4482 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1669729 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1669832 T4486 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> 1669832 T4487 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> 1670227 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1670232 T4488 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1670233 T4482 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1670234 T4482 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> 1670234 T4482 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1670234 T4482 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1670336 T4487 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> 1670336 T4486 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> 1670732 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1670738 T4489 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1670738 T4485 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@1387d6 rejected from java.util.concurrent.ThreadPoolExecutor@3b2a08[Shutting down, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 8]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:201)
[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> 1672238 T4486 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1672241 T4468 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57571 57571
[junit4] 2> 1672878 T4469 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57571 57571
[junit4] 2> 1672880 T4468 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 1672880 T4482 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57571_solr
[junit4] 2> 1672882 T4491 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1672885 T4468 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1672885 T4468 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1672886 T4492 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1672986 T4468 oasc.ZkTestServer.run start zk server on port:41987
[junit4] 2> 1672987 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1672989 T4498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1901345 name:ZooKeeperConnection Watcher:127.0.0.1:41987/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1672989 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1672990 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1672991 T4500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d18398 name:ZooKeeperConnection Watcher:127.0.0.1:41987 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1672991 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1673001 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1673002 T4502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1affb57 name:ZooKeeperConnection Watcher:127.0.0.1:41987 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1673002 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1673002 T4468 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1673005 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1673006 T4468 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1673008 T4468 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1673009 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1673012 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1673013 T4504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cc6522 name:ZooKeeperConnection Watcher:127.0.0.1:41987/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1673013 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1673013 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1673015 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1673018 T4468 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:41987_solr
[junit4] 2> 1673018 T4468 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1673020 T4468 oasc.Overseer.start Overseer (id=92268298915741699-127.0.0.1:41987_solr-n_0000000000) starting
[junit4] 2> 1673021 T4468 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1673023 T4468 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1673024 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1673026 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1673028 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1673030 T4468 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1673033 T4506 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1673034 T4505 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1673035 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1673036 T4505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1673036 T4505 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> 1673036 T4505 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1673038 T4507 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1673038 T4508 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> 1673086 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1673088 T4507 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1673089 T4505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1673090 T4505 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> 1673090 T4505 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1673090 T4505 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1673192 T4508 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> 1673240 T4468 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41987 41987
[junit4] 2> 1673949 T4492 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41987 41987
[junit4] 2> 1673951 T4468 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 1673952 T4505 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:41987_solr
[junit4] 2> 1673953 T4509 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1673956 T4468 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1673957 T4468 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1673958 T4510 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1674058 T4468 oasc.ZkTestServer.run start zk server on port:47869
[junit4] 2> 1674059 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674063 T4516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8aac35 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674064 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674065 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674066 T4518 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c321e7 name:ZooKeeperConnection Watcher:127.0.0.1:47869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674066 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674069 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674070 T4520 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31ef49 name:ZooKeeperConnection Watcher:127.0.0.1:47869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674071 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674071 T4468 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1674075 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1674091 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674091 T4521 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674093 T4524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f55f38 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674093 T4525 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f3dd8 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674093 T4521 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674094 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674094 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1674095 T4468 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1674097 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1674097 T4468 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1674100 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1674102 T4521 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47869_solr
[junit4] 2> 1674102 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1674103 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1674104 T4521 oasc.Overseer.start Overseer (id=92268298985996291-127.0.0.1:47869_solr-n_0000000000) starting
[junit4] 2> 1674105 T4521 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1674105 T4468 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1674107 T4521 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1674109 T4521 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1674110 T4521 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1674112 T4521 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1674113 T4521 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1674117 T4528 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1674117 T4521 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1674117 T4527 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1674118 T4527 oasc.Overseer$ClusterStateUpdater.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.amILeader(Overseer.java:602)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:207)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1674118 T4521 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674118 T4527 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=92268298985996291-127.0.0.1:47869_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1674119 T4527 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:47869_solr
[junit4] 2> 1674119 T4530 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f5cc9d name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674119 T4521 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674120 T4531 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1674120 T4528 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:251)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:248)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:248)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:256)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1674121 T4521 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47869_solr
[junit4] 2> 1674122 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1674123 T4521 oasc.Overseer.start Overseer (id=92268298985996293-127.0.0.1:47869_solr-n_0000000001) starting
[junit4] 2> 1674127 T4533 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1674128 T4532 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1674131 T4532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1674132 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1674132 T4532 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1674132 T4532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1674134 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1674135 T4526 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> 1674607 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1674613 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1674615 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1674616 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1674617 T4532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1674619 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1674619 T4532 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1674620 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1674621 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1674622 T4536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@670646 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1674622 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1674623 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1674624 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1674627 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1674627 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1674628 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1674628 T4532 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1674631 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1674731 T4537 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1674731 T4526 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1674832 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1674834 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1674836 T4532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1674836 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1674837 T4532 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1674837 T4532 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1674939 T4526 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1674939 T4537 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1675335 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1675340 T4525 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@106de02 rejected from java.util.concurrent.ThreadPoolExecutor@1d9925a[Shutting down, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 5]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:201)
[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> 1675340 T4538 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1675341 T4537 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1675343 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1675344 T4532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1675447 T4537 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> 1676839 T4526 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1676840 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1676842 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1676843 T4540 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8705e4 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1676843 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1676844 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1676846 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1676850 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1676850 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1676851 T4532 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1676852 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676852 T4532 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676855 T4541 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1676856 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1676856 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1676857 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676857 T4532 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676859 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1676861 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1676862 T4543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1204a01 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1676862 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1676863 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1676864 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1676867 T4534 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1676867 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1676868 T4532 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676868 T4532 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676870 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1676930 T4521 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1676932 T4521 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1676933 T4546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@102ffb4 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1676933 T4521 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1676933 T4532 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:47869_solr
[junit4] 2> 1676935 T4547 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1676936 T4521 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47869_solr
[junit4] 2> 1676936 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1676937 T4521 oasc.Overseer.start Overseer (id=92268298985996297-127.0.0.1:47869_solr-n_0000000002) starting
[junit4] 2> 1676942 T4549 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1676944 T4548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1676944 T4548 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1676945 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676945 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676945 T4541 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676945 T4544 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676947 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676947 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676948 T4544 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676948 T4541 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676950 T4544 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676950 T4541 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676951 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1676952 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1676952 T4544 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676952 T4541 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1676954 T4548 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1677072 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1677074 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1677074 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1677076 T4548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1677076 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1677076 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1677079 T4551 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1677079 T4544 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1677082 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1677184 T4544 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> 1678579 T4541 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1678582 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1678585 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1678586 T4553 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bbbe1 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1678586 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1678588 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1678591 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1678596 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678596 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1678597 T4548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1678598 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1678598 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678601 T4554 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1678601 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1678602 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678602 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1678603 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678605 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1678605 T4556 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cfedaf name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1678606 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1678606 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678606 T4554 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> 1678606 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1678608 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1678611 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678611 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1678611 T4548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1678612 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1678612 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678614 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1678616 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678616 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1678617 T4548 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1678617 T4548 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678621 T4558 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1678621 T4557 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1678624 T4550 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1678643 T4521 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1678645 T4521 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1678646 T4560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14af7ed name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1678647 T4521 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1678647 T4548 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:47869_solr
[junit4] 2> 1678648 T4561 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1678650 T4521 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47869_solr
[junit4] 2> 1678650 T4521 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1678652 T4521 oasc.Overseer.start Overseer (id=92268298985996300-127.0.0.1:47869_solr-n_0000000003) starting
[junit4] 2> 1678656 T4563 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1678658 T4562 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1678658 T4562 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1678659 T4562 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1678659 T4562 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678659 T4557 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> 1678661 T4562 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1678661 T4562 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1678661 T4557 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> 1678663 T4557 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> 1678664 T4562 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1680121 T4554 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$7.execute(SolrZkClient.java:285)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[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:282)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1680122 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1680124 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1680125 T4565 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44698a name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1680125 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1680126 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1680128 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1680132 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1680132 T4567 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1680134 T4562 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1680134 T4562 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1680135 T4562 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1680138 T4566 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1680138 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1680139 T4567 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1680139 T4562 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1680140 T4562 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1680142 T4468 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1680143 T4569 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@da5423 name:ZooKeeperConnection Watcher:127.0.0.1:47869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1680143 T4468 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1680143 T4567 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1680144 T4566 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> 1680144 T4468 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1680146 T4468 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1680148 T4567 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1680148 T4468 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1680149 T4562 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1680149 T4562 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1680149 T4562 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1680151 T4468 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1680153 T4567 oasc.DistributedQueue$LatchChildWatcher.process Latc
[...truncated too long message...]
Path(SolrZkClient.java:442)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] 2> ... 10 more
[junit4] 2>
[junit4] 2> 1737161 T5075 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard13
[junit4] 2> 1737163 T4839 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x147cd883868004c, 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> 1737165 T5078 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard11
[junit4] 2> 1738665 T5075 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard13
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] 2> ... 10 more
[junit4] 2>
[junit4] 2> 1738671 T4468 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45495 45495
[junit4] 2> 1739500 T4838 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:45495 45495
[junit4] 2> 1739506 T4468 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
[junit4] 2> 1739506 T4851 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:45495_solr
[junit4] 2> 1739507 T5212 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$8.execute(SolrZkClient.java:302)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[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:299)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1742508 T4468 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-6641C8D44BE5DD9F-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene49), sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ar_SD, timezone=MST
[junit4] 2> NOTE: Linux 3.13.0-32-generic i386/Oracle Corporation 1.7.0_65 (32-bit)/cpus=8,threads=1,free=117133880,total=395411456
[junit4] 2> NOTE: All tests run in this JVM: [PathHierarchyTokenizerFactoryTest, TestInitQParser, DocValuesMultiTest, TestSolrXmlPersistence, TimeZoneUtilsTest, TestSolrIndexConfig, TestConfig, DisMaxRequestHandlerTest, CustomCollectionTest, FileUtilsTest, SuggesterTest, ClusterStateUpdateTest, DirectSolrSpellCheckerTest, TestLMDirichletSimilarityFactory, TestStandardQParsers, AnalyticsMergeStrategyTest, TestCoreDiscovery, TestHashPartitioner, TestNoOpRegenerator, TestFaceting, TestDynamicFieldCollectionResource, BadComponentTest, PingRequestHandlerTest, TestLRUCache, TestArbitraryIndexDir, TestChildDocTransformer, SyncSliceTest, TestDocBasedVersionConstraints, OverseerCollectionProcessorTest, EchoParamsTest, TermsComponentTest, TestComplexPhraseQParserPlugin, TestBinaryResponseWriter, TestRequestStatusCollectionAPI, TestFoldingMultitermQuery, TestDocSet, SystemInfoHandlerTest, ZkCLITest, TestAnalyzedSuggestions, ResponseLogComponentTest, TestLuceneMatchVersion, SolrIndexSplitterTest, SSLMigrationTest, SuggesterTSTTest, TestFieldTypeResource, TestSolr4Spatial, AddSchemaFieldsUpdateProcessorFactoryTest, BadIndexSchemaTest, PrimitiveFieldTypeTest, SolrCmdDistributorTest, SpellCheckCollatorTest, TestManagedStopFilterFactory, ReplicationFactorTest, HdfsSyncSliceTest, FunctionTest, ResponseHeaderTest, RecoveryZkTest, HighlighterTest, TestDFRSimilarityFactory, TestSolrCoreProperties, TestDocumentBuilder, TestFastWriter, FastVectorHighlighterTest, TestSchemaResource, TestManagedSynonymFilterFactory, SolrXmlInZkTest, TestClassNameShortening, ParsingFieldUpdateProcessorsTest, HdfsWriteToMultipleCollectionsTest, WordBreakSolrSpellCheckerTest, FieldMutatingUpdateProcessorTest, OverseerStatusTest, SuggesterWFSTTest, HighlighterMaxOffsetTest, TestIntervalFaceting, TestSearcherReuse, TestManagedResourceStorage, TestSort, IndexSchemaTest, TestAnalyzeInfixSuggestions, TestCodecSupport, XmlUpdateRequestHandlerTest, OpenExchangeRatesOrgProviderTest, ChaosMonkeyNothingIsSafeTest, CursorMarkTest, AssignTest, DirectUpdateHandlerTest, SpellCheckComponentTest, QueryResultKeyTest, TestReplicationHandler, TestStressRecovery, PreAnalyzedUpdateProcessorTest, ZkControllerTest, TestFieldResource, MinimalSchemaTest, TestRandomDVFaceting, AddBlockUpdateTest, PluginInfoTest, ExternalFileFieldSortTest, FieldFacetTest, TestSolrDeletionPolicy1, RegexBoostProcessorTest, TestTolerantSearch, BasicDistributedZkTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OverseerTest]
[junit4] Completed on J0 in 75.05s, 9 tests, 1 error <<< FAILURES!
[...truncated 661 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:474: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:454: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1307: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:922: There were test failures: 421 suites, 1761 tests, 1 error, 39 ignored (18 assumptions)
Total time: 102 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.7.0_65 -client -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any