Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.10-Linux/67/
Java: 64bit/jdk1.7.0_67 -XX:-UseCompressedOops -XX:+UseParallelGC (asserts:
true)
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([5521FA015B1A02AA:512975F249BFED8B]:0)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
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:157)
at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java: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:54)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
... 48 more
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:462)
at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 49 more
Build Log:
[...truncated 11631 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build/solr-core/test/J1/./solr.cloud.OverseerTest-5521FA015B1A02AA-001/init-core-data-001
[junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1620465 T4352 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1620468 T4352 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 1620468 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1620469 T4353 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1620569 T4352 oasc.ZkTestServer.run start zk server on
port:32998
[junit4] 2> 1620570 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1620575 T4359 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@39bebd5f
name:ZooKeeperConnection Watcher:127.0.0.1:32998 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620575 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1620579 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1620581 T4361 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@36b98a2f
name:ZooKeeperConnection Watcher:127.0.0.1:32998 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620582 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1620582 T4352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1620589 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1620591 T4363 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4fbb50df
name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620591 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1620591 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1620595 T4352 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1620598 T4352 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1620600 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1620605 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1620607 T4365 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@339416c9
name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620607 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1620609 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1620613 T4352 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1620617 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1620619 T4369 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@74e0321d
name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1620619 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1620620 T4352 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1620622 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1620624 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1620627 T4352 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1620629 T4352 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:32998_solr
[junit4] 2> 1620630 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1620632 T4352 oasc.Overseer.start Overseer
(id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) starting
[junit4] 2> 1620633 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1620636 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1620639 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1620643 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1620647 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1620651 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1620656 T4352 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1620657 T4371 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1620658 T4370 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1621659 T4373 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1621661 T4370 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1621662 T4370
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1621662 T4370 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1621664 T4367 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> 1621664 T4366 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> 1622159 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1622165 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1622168 T4373 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1622169 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1622170 T4370 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1622170 T4370 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1622171 T4373 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1622172 T4366 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> 1622172 T4367 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> 1622660 T4371 oasc.OverseerCollectionProcessor.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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:272)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1622660 T4371 oasc.OverseerCollectionProcessor.amILeader
According to ZK I (id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 1623226 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1623230 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1623231 T4375 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@24384e8c
name:ZooKeeperConnection Watcher:127.0.0.1:32998/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1623231 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1623231 T4352 oasc.Overseer.close Overseer
(id=92765866147905540-127.0.0.1:32998_solr-n_0000000000) closing
[junit4] 2> 1623232 T4370 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:32998_solr
[junit4] 2> 1623233 T4352 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1623234 T4376
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1623235 T4352 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1623236 T4352 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:32998_solr
[junit4] 2> 1623236 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1623237 T4352 oasc.Overseer.start Overseer
(id=92765866147905541-127.0.0.1:32998_solr-n_0000000001) starting
[junit4] 2> 1623242 T4352 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1623243 T4378 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1623243 T4377 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1623245 T4377 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1623245 T4377 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1623246 T4380 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1623246 T4367 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> 1623246 T4366 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> 1623299 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1623299 T4380 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1623304 T4352 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92765866147905539-node1_core1-n_0000000002
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at
org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1623306 T4377 oasc.SolrException.log ERROR Problem cleaning up
collection in
zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException:
KeeperErrorCode = Directory not empty for
/collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:189)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:670)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1104)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:362)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:244)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1623306 T4381 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1623305 T4366 oasc.LeaderElector.checkIfIamLeader WARN Our
node is no longer in line to be leader
[junit4] 2> 1623306 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1623309 T4380 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1623310 T4377 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1623413 T4367 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> 1623413 T4381 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> 1624309 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1625312 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1626314 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1627316 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1628320 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1629322 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1630326 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1631328 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1632331 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1633333 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1634336 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1635338 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1636340 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1637342 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1638345 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1638352 T4352 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:32998 32998
[junit4] 2> 1639026 T4353 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:32998 32998
[junit4] 2> 1639028 T4352 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 1639028 T4352 oasc.Overseer.close Overseer
(id=92765866147905541-127.0.0.1:32998_solr-n_0000000001) closing
[junit4] 2> 1639028 T4377 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:32998_solr
[junit4] 2> 1639030 T4382
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=5521FA015B1A02AA
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_PR
-Dtests.timezone=Europe/Tiraspol -Dtests.asserts=true
-Dtests.file.encoding=US-ASCII
[junit4] ERROR 18.6s J1 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not
register as the leader because creating the ephemeral registration node in
ZooKeeper failed
[junit4] > at
__randomizedtesting.SeedInfo.seed([5521FA015B1A02AA:512975F249BFED8B]:0)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] > at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] > at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] > ... 48 more
[junit4] > Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
[junit4] > at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 49 more
[junit4] 2> 1639043 T4352 oas.SolrTestCaseJ4.setUp ###Starting
testStateChange
[junit4] 2> 1639044 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1639045 T4383 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1639144 T4352 oasc.ZkTestServer.run start zk server on
port:44886
[junit4] 2> 1639145 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1639148 T4389 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2a59f3ee
name:ZooKeeperConnection Watcher:127.0.0.1:44886/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1639148 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1639149 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1639150 T4391 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@32ebfc0a
name:ZooKeeperConnection Watcher:127.0.0.1:44886 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1639150 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1639152 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1639153 T4393 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4ceb9b64
name:ZooKeeperConnection Watcher:127.0.0.1:44886 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1639153 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1639154 T4352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1639157 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1639159 T4352 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1639161 T4352 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1639162 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1639163 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1639164 T4395 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@19043c85
name:ZooKeeperConnection Watcher:127.0.0.1:44886/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1639164 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1639165 T4352 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1639166 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1639167 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1639168 T4352 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1639169 T4352 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:44886_solr
[junit4] 2> 1639169 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1639170 T4352 oasc.Overseer.start Overseer
(id=92765867365302275-127.0.0.1:44886_solr-n_0000000000) starting
[junit4] 2> 1639171 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1639172 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1639174 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1639175 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1639176 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1639178 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1639180 T4352 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1639181 T4397 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1639181 T4396 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1639183 T4396 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> 1639183 T4396 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1639184 T4399 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1639184 T4400 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> 1639234 T4399 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1639235 T4396 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> 1639236 T4396 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 1639236 T4396 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1639339 T4400 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> 1639387 T4352 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:44886 44886
[junit4] 2> 1639955 T4383 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:44886 44886
[junit4] 2> 1639956 T4352 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 1639956 T4352 oasc.Overseer.close Overseer
(id=92765867365302275-127.0.0.1:44886_solr-n_0000000000) closing
[junit4] 2> 1639957 T4396 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:44886_solr
[junit4] 2> 1639959 T4401
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1639966 T4352 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignment
[junit4] 2> 1639967 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1639968 T4402 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1640067 T4352 oasc.ZkTestServer.run start zk server on
port:40082
[junit4] 2> 1640069 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1640071 T4408 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4becc9ef
name:ZooKeeperConnection Watcher:127.0.0.1:40082 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1640071 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1640073 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1640074 T4410 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4a26d9a7
name:ZooKeeperConnection Watcher:127.0.0.1:40082 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1640074 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1640075 T4352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1640079 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1640080 T4412 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3dd5dc8b
name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1640080 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1640080 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1640083 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1640084 T4414 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@26686864
name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1640084 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1640085 T4352 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1640087 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1640090 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1640091 T4352 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1640093 T4352 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:40082_solr
[junit4] 2> 1640093 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1640095 T4352 oasc.Overseer.start Overseer
(id=92765867425857539-127.0.0.1:40082_solr-n_0000000000) starting
[junit4] 2> 1640097 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1640100 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1640103 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1640105 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1640108 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1640111 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1640114 T4352 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1640115 T4416 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1640116 T4352 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1640116 T4415 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1640117 T4352 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1640118 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1640119 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1640120 T4419 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@522c03b7
name:ZooKeeperConnection Watcher:127.0.0.1:40082/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1640120 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1640122 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1640123 T4352 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1640127 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1640128 T4415 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> 1640128 T4415
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1640128 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1640131 T4421 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> 1640131 T4420 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> 1640627 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1640632 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1640634 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1640636 T4415 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> 1640637 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1640637 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1640638 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1640638 T4421 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> 1640639 T4420 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> 1641135 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1641140 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1641142 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1641145 T4415 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> 1641145 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1641145 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1641146 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1641147 T4420 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> 1641147 T4421 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> 1641643 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1641647 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1641649 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1641652 T4415 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> 1641652 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1641652 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1641653 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1641654 T4421 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> 1641654 T4420 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> 1642150 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1642155 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1642156 T4415 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> 1642156 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1642156 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1642259 T4421 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> 1642259 T4420 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> 1642655 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1642659 T4422 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1642660 T4415 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> 1642660 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1642661 T4415 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1642763 T4420 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> 1642763 T4421 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> 1643159 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1643164 T4423 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:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[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:209)
[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> 1643164 T4419 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@78c2a1bb rejected from
java.util.concurrent.ThreadPoolExecutor@320839ed[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:206)
[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> 1644664 T4421 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:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[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:209)
[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> 1644667 T4352 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40082 40082
[junit4] 2> 1645376 T4402 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40082 40082
[junit4] 2> 1645377 T4352 oas.SolrTestCaseJ4.tearDown ###Ending
testShardAssignment
[junit4] 2> 1645378 T4352 oasc.Overseer.close Overseer
(id=92765867425857539-127.0.0.1:40082_solr-n_0000000000) closing
[junit4] 2> 1645378 T4415 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:40082_solr
[junit4] 2> 1645381 T4425
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1645385 T4352 oas.SolrTestCaseJ4.setUp ###Starting
testBadQueueItem
[junit4] 2> 1645386 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1645387 T4426 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1645487 T4352 oasc.ZkTestServer.run start zk server on
port:51839
[junit4] 2> 1645488 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1645490 T4432 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1ff114d5
name:ZooKeeperConnection Watcher:127.0.0.1:51839 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1645490 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1645492 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1645493 T4434 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3710c3f5
name:ZooKeeperConnection Watcher:127.0.0.1:51839 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1645493 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1645493 T4352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1645497 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1645498 T4436 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@75b2f026
name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1645498 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1645498 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1645500 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1645501 T4438 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2ff1aa75
name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1645501 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1645501 T4352 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1645502 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1645504 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1645505 T4352 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1645507 T4352 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:51839_solr
[junit4] 2> 1645507 T4352 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1645508 T4352 oasc.Overseer.start Overseer
(id=92765867780931587-127.0.0.1:51839_solr-n_0000000000) starting
[junit4] 2> 1645510 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1645511 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1645513 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1645515 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1645516 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1645518 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1645520 T4352 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1645520 T4440 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1645521 T4352 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1645521 T4439 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1645522 T4352 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1645523 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1645525 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1645525 T4443 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@10dfd41c
name:ZooKeeperConnection Watcher:127.0.0.1:51839/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1645526 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1645527 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1645529 T4352 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1645531 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1645532 T4439 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> 1645532 T4439
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1645532 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1645534 T4445 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> 1645534 T4444 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> 1646031 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1646044 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1646051 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1646057 T4439 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> 1646057 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1646058 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1646061 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1646062 T4445 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> 1646062 T4444 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> 1646553 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1646557 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1646560 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1646565 T4439 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> 1646565 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1646565 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1646568 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1646569 T4445 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> 1646569 T4444 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> 1647062 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1647066 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1647069 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1647172 T4444 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> 1647172 T4445 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> 1647222 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1647223 T4439
oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid
Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1647226 T4439
oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid
Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 1647229 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1647229 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1647229 T4439
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 1647230 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1647333 T4444 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> 1647333 T4445 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> 1647724 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard1/election
[junit4] 2> 1647729 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard1
[junit4] 2> 1647732 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1647734 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1647734 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1647735 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1647736 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1647736 T4445 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> 1647736 T4444 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> 1648233 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard3/election
[junit4] 2> 1648237 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard3
[junit4] 2> 1648239 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1648241 T4439 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1648243 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1648243 T4444 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> 1648243 T4445 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> 1648740 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard2/election
[junit4] 2> 1648744 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard2
[junit4] 2> 1648746 T4446 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1648849 T4445 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> 1648849 T4444 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> 1650399 T4445 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1650401 T4352 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:51839 51839
[junit4] 2> 1651055 T4426 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:51839 51839
[junit4] 2> 1651056 T4352 oas.SolrTestCaseJ4.tearDown ###Ending
testBadQueueItem
[junit4] 2> 1651056 T4352 oasc.Overseer.close Overseer
(id=92765867780931587-127.0.0.1:51839_solr-n_0000000000) closing
[junit4] 2> 1651057 T4439 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:51839_solr
[junit4] 2> 1651059 T4447
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1651062 T4352 oas.SolrTestCaseJ4.setUp ###Starting
testShardLeaderChange
[junit4] 2> 1651063 T4352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1651063 T4448 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1651163 T4352 oasc.ZkTestServer.run start zk server on
port:45641
[junit4] 2> 1651164 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1651173 T4454 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@490e490e
name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1651174 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1651174 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1651176 T4456 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7bde31f name:ZooKeeperConnection
Watcher:127.0.0.1:45641 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1651176 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1651178 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1651179 T4458 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3bc24107
name:ZooKeeperConnection Watcher:127.0.0.1:45641 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1651179 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1651179 T4352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1651182 T4352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1651186 T4459 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1651186 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1651187 T4462 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4e28e718
name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1651187 T4459 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1651187 T4463 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@344d8833
name:ZooKeeperConnection Watcher:127.0.0.1:45641/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1651187 T4459 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1651187 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1651188 T4459 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1651188 T4352 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1651189 T4459 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1651190 T4352 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1651190 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1651190 T4459 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1651192 T4459 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:45641_solr
[junit4] 2> 1651192 T4459 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1651192 T4352 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1651193 T4459 oasc.Overseer.start Overseer
(id=92765868152913923-127.0.0.1:45641_solr-n_0000000000) starting
[junit4] 2> 1651194 T4352 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1651194 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1651196 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1651197 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1651198 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1651199 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1651201 T4459 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1651203 T4459 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpir
[...truncated too long message...]
] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1716536 T5166
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1716536 T5166 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1716537 T5169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1716537 T5163 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> 1716538 T5162 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> 1717035 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1717040 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1717042 T5169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1717044 T4352 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1717045 T5171 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@9764032 name:ZooKeeperConnection
Watcher:127.0.0.1:40514/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1717045 T4352 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1717046 T4352
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1717047 T4352 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1717048 T5169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1717048 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1717049 T5166 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1717049 T5166 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1717051 T4352 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1717053 T5169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1717155 T5172 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> 1717155 T5162 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> 1717158 T4352 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40514 40514
[junit4] 2> 1717587 T5149 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40514 40514
[junit4] 2> 1717588 T4352 oas.SolrTestCaseJ4.tearDown ###Ending
testDoubleAssignment
[junit4] 2> 1717588 T4352 oasc.Overseer.close Overseer
(id=92765872434970628-127.0.0.1:40514_solr-n_0000000000) closing
[junit4] 2> 1717588 T5166 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:40514_solr
[junit4] 2> 1717589 T5173
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:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1720589 T4352 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build/solr-core/test/J1/./solr.cloud.OverseerTest-5521FA015B1A02AA-001
[junit4] 2> NOTE: test params are: codec=Lucene410: {}, docValues:{},
sim=DefaultSimilarity, locale=es_PR, timezone=Europe/Tiraspol
[junit4] 2> NOTE: Linux 3.13.0-39-generic amd64/Oracle Corporation
1.7.0_67 (64-bit)/cpus=8,threads=1,free=124961328,total=425721856
[junit4] 2> NOTE: All tests run in this JVM:
[HdfsChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, SampleTest,
TimeZoneUtilsTest, HdfsLockFactoryTest,
DistribDocExpirationUpdateProcessorTest, TestRecovery, TestQuerySenderNoQuery,
QueryParsingTest, SolrInfoMBeanTest, StressHdfsTest, SearchHandlerTest,
FieldAnalysisRequestHandlerTest, DistributedDebugComponentTest,
AtomicUpdatesTest, LukeRequestHandlerTest, OverseerRolesTest,
CachingDirectoryFactoryTest, PrimUtilsTest, ScriptEngineTest, AssignTest,
TestConfigSets, URLClassifyProcessorTest, OverseerStatusTest,
TestDistributedMissingSort, CircularListTest,
DistributedQueryComponentCustomSortTest, RollingRestartTest, DateFieldTest,
SolrRequestParserTest, DOMUtilTest, TestSolrQueryParserResource,
TestExpandComponent, TestFunctionQuery, BasicZkTest, AlternateDirectoryTest,
AnalysisAfterCoreReloadTest, TestReplicationHandlerBackup, AutoCommitTest,
TestSweetSpotSimilarityFactory, TestJoin, TestClassNameShortening,
TestBinaryField, TestRecoveryHdfs, BlockCacheTest, SystemInfoHandlerTest,
DefaultValueUpdateProcessorTest, FullSolrCloudDistribCmdsTest,
DebugComponentTest, SchemaVersionSpecificBehaviorTest,
TestExtendedDismaxParser, SolrCoreTest, TestFileDictionaryLookup,
StatsComponentTest, TestLRUCache, TestManagedResourceStorage,
SynonymTokenizerTest, TestHighFrequencyDictionaryFactory, TestFastLRUCache,
TestReRankQParserPlugin, LegacyHTMLStripCharFilterTest,
UpdateRequestProcessorFactoryTest, HdfsUnloadDistributedZkTest,
SpatialFilterTest, TestUpdate, HardAutoCommitTest, MultiTermTest,
TestDistributedGrouping, HdfsWriteToMultipleCollectionsTest,
ChaosMonkeySafeLeaderTest, RemoteQueryErrorTest, TestStandardQParsers,
AsyncMigrateRouteKeyTest, DistributedFacetPivotLargeTest,
CurrencyFieldXmlFileTest, TestIndexingPerformance,
BinaryUpdateRequestHandlerTest, FileBasedSpellCheckerTest, TestCSVLoader,
TestSolrQueryParser, HdfsDirectoryTest, TestShortCircuitedRequests,
TestCharFilters, SuggesterFSTTest, TestOmitPositions, CacheHeaderTest,
TestManagedResource, TestFieldTypeCollectionResource, TestNonNRTOpen,
TestMaxScoreQueryParser, CopyFieldTest, TestDynamicFieldCollectionResource,
IndexSchemaRuntimeFieldTest, DistanceFunctionTest, ResponseHeaderTest,
TestElisionMultitermQuery, DistributedFacetPivotSmallTest, SSLMigrationTest,
TestQueryTypes, TestPostingsSolrHighlighter, NumericFieldsTest,
TestLMDirichletSimilarityFactory, BasicDistributedZk2Test,
OpenCloseCoreStressTest, OverseerTest]
[junit4] Completed on J1 in 100.14s, 9 tests, 1 error <<< FAILURES!
[...truncated 682 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:474: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:454: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/build.xml:45: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/solr/common-build.xml:494:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/lucene/common-build.xml:1350:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.10-Linux/lucene/common-build.xml:970:
There were test failures: 421 suites, 1742 tests, 1 error, 38 ignored (17
assumptions)
Total time: 95 minutes 42 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0_67
-XX:-UseCompressedOops -XX:+UseParallelGC (asserts: true)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
