Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11086/
Java: 64bit/jdk1.7.0_67 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration
node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because
creating the ephemeral registration node in ZooKeeper failed
at
__randomizedtesting.SeedInfo.seed([20505546D23B741:60D8AA77F865860]: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.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java: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:31)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
... 47 more
Build Log:
[...truncated 11454 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-20505546D23B741-001/init-core-data-001
[junit4] 2> 1588232 T4315 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(true) and clientAuth (true)
[junit4] 2> 1588233 T4315 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1588233 T4315 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1588236 T4315 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignment
[junit4] 2> 1588237 T4315 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1588238 T4316 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1588337 T4315 oasc.ZkTestServer.run start zk server on
port:48876
[junit4] 2> 1588338 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1588341 T4322 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@ffcce28 name:ZooKeeperConnection
Watcher:127.0.0.1:48876 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1588341 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1588344 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1588345 T4324 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7e13c12d
name:ZooKeeperConnection Watcher:127.0.0.1:48876 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1588345 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1588346 T4315 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1588353 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1588353 T4326 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@70fe9f9f
name:ZooKeeperConnection Watcher:127.0.0.1:48876/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1588354 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1588354 T4315 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1588358 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1588360 T4328 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@102f3a5d
name:ZooKeeperConnection Watcher:127.0.0.1:48876/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1588360 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1588361 T4315 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1588362 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1588364 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1588366 T4315 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1588367 T4315 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:48876_solr
[junit4] 2> 1588368 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1588369 T4315 oasc.Overseer.start Overseer
(id=92326958919188483-127.0.0.1:48876_solr-n_0000000000) starting
[junit4] 2> 1588371 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1588375 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1588377 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1588379 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1588380 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1588383 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1588389 T4315 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1588390 T4330 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1588391 T4315 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1588392 T4329 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1588395 T4315 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1588396 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1588413 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1588415 T4333 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@fce9cd4 name:ZooKeeperConnection
Watcher:127.0.0.1:48876/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1588415 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1588417 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1588418 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1588429 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1588431 T4329 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> 1588431 T4329
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1588432 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1588434 T4334 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> 1588434 T4335 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> 1588926 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1588931 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1588934 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1588937 T4329 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> 1588937 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1588937 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1588939 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1588940 T4335 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> 1588945 T4334 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> 1589435 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1589439 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1589443 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1589447 T4329 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> 1589448 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1589448 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1589449 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1589556 T4335 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> 1589556 T4334 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> 1589945 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1589950 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1589953 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1589956 T4329 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> 1589957 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1589957 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1589958 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1590060 T4334 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> 1590060 T4335 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> 1590455 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1590460 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1590462 T4329 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> 1590462 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1590462 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1590565 T4335 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> 1590565 T4334 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> 1590961 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1590966 T4336 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1590968 T4329 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> 1590968 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1590968 T4329 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1591071 T4335 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> 1591071 T4334 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> 1591466 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1591476 T4333 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@6a5204ca rejected from
java.util.concurrent.ThreadPoolExecutor@2eb8a04e[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> 1591477 T4337 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> 1592976 T4335 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> 1592979 T4315 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:48876 48876
[junit4] 2> 1593675 T4316 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:48876 48876
[junit4] 2> 1593676 T4315 oas.SolrTestCaseJ4.tearDown ###Ending
testShardAssignment
[junit4] 2> 1593677 T4315 oasc.Overseer.close Overseer
(id=92326958919188483-127.0.0.1:48876_solr-n_0000000000) closing
[junit4] 2> 1593678 T4329 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:48876_solr
[junit4] 2> 1593679 T4339
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1593683 T4315 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1593684 T4315 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1593685 T4340 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1593784 T4315 oasc.ZkTestServer.run start zk server on
port:53420
[junit4] 2> 1593785 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1593788 T4346 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@55cdaed8
name:ZooKeeperConnection Watcher:127.0.0.1:53420/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1593788 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1593790 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1593791 T4348 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@402c21ef
name:ZooKeeperConnection Watcher:127.0.0.1:53420 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1593791 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1593793 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1593795 T4350 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@113c54d4
name:ZooKeeperConnection Watcher:127.0.0.1:53420 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1593795 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1593795 T4315 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1593798 T4315 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1593800 T4315 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1593802 T4315 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1593804 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1593806 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1593809 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1593811 T4352 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@248db0b3
name:ZooKeeperConnection Watcher:127.0.0.1:53420/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1593811 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1593812 T4315 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1593815 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1593818 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1593820 T4315 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1593821 T4315 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:53420_solr
[junit4] 2> 1593821 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1593823 T4315 oasc.Overseer.start Overseer
(id=92326959276097539-127.0.0.1:53420_solr-n_0000000000) starting
[junit4] 2> 1593825 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1593829 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1593832 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1593835 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1593837 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1593851 T4315 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1593852 T4354 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1593856 T4353 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 1593857 T4353 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1593858 T4356 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> 1593859 T4353 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1593860 T4356 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> 1593861 T4353 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1593862 T4353 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1593863 T4357 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1593864 T4356 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> 1593957 T4315 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:53420 53420
[junit4] 2> 1594506 T4340 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:53420 53420
[junit4] 2> 1594507 T4315 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1594508 T4315 oasc.Overseer.close Overseer
(id=92326959276097539-127.0.0.1:53420_solr-n_0000000000) closing
[junit4] 2> 1594508 T4353 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:53420_solr
[junit4] 2> 1594515 T4358
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1594515 T4315 oas.SolrTestCaseJ4.setUp ###Starting
testBadQueueItem
[junit4] 2> 1594516 T4315 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1594517 T4359 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1594617 T4315 oasc.ZkTestServer.run start zk server on
port:52292
[junit4] 2> 1594618 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1594621 T4365 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3d4603e4
name:ZooKeeperConnection Watcher:127.0.0.1:52292 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1594621 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1594626 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1594627 T4367 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4f94df2 name:ZooKeeperConnection
Watcher:127.0.0.1:52292 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1594627 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1594628 T4315 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1594631 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1594632 T4369 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@55e25fd7
name:ZooKeeperConnection Watcher:127.0.0.1:52292/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1594633 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1594633 T4315 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1594637 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1594637 T4371 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5b9a6c6a
name:ZooKeeperConnection Watcher:127.0.0.1:52292/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1594638 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1594638 T4315 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1594641 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1594643 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1594645 T4315 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1594646 T4315 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:52292_solr
[junit4] 2> 1594646 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1594647 T4315 oasc.Overseer.start Overseer
(id=92326959330623491-127.0.0.1:52292_solr-n_0000000000) starting
[junit4] 2> 1594650 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1594654 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1594657 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1594666 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1594669 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1594672 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1594682 T4315 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1594683 T4373 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1594683 T4315 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1594684 T4372 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1594685 T4315 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1594686 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1594688 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1594690 T4376 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7d425f56
name:ZooKeeperConnection Watcher:127.0.0.1:52292/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1594690 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1594691 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1594693 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1594699 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1594701 T4372 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> 1594702 T4372
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1594702 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1594704 T4377 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> 1594704 T4378 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> 1595199 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1595205 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1595209 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1595213 T4372 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> 1595213 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1595213 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1595215 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1595216 T4378 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> 1595217 T4377 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> 1595710 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1595715 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1595718 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1595722 T4372 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> 1595723 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1595723 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1595724 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1595826 T4377 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> 1595826 T4378 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> 1596224 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1596231 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1596233 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1596337 T4378 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> 1596337 T4377 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> 1596385 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1596386 T4372
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> 1596388 T4372
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> 1596389 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1596390 T4372 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> 1596390 T4372
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 1596390 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1596492 T4377 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> 1596492 T4378 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> 1596886 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard3/election
[junit4] 2> 1596891 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard3
[junit4] 2> 1596894 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1596898 T4372 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> 1596898 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1596898 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1596899 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1596900 T4378 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> 1596900 T4377 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> 1597396 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard1/election
[junit4] 2> 1597400 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard1
[junit4] 2> 1597403 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1597406 T4372 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> 1597406 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1597406 T4372 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1597408 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1597408 T4377 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> 1597408 T4378 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> 1597904 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard2/election
[junit4] 2> 1597910 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard2
[junit4] 2> 1597912 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1598016 T4378 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> 1598016 T4377 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> 1598067 T4315 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:52292 52292
[junit4] 2> 1598639 T4359 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:52292 52292
[junit4] 2> 1598641 T4315 oas.SolrTestCaseJ4.tearDown ###Ending
testBadQueueItem
[junit4] 2> 1598641 T4315 oasc.Overseer.close Overseer
(id=92326959330623491-127.0.0.1:52292_solr-n_0000000000) closing
[junit4] 2> 1598642 T4372 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:52292_solr
[junit4] 2> 1598645 T4380
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1598650 T4315 oas.SolrTestCaseJ4.setUp ###Starting
testShardLeaderChange
[junit4] 2> 1598651 T4315 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1598652 T4381 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1598752 T4315 oasc.ZkTestServer.run start zk server on
port:41539
[junit4] 2> 1598753 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598755 T4387 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2d92ced name:ZooKeeperConnection
Watcher:127.0.0.1:41539/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1598755 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598756 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598757 T4389 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3583c567
name:ZooKeeperConnection Watcher:127.0.0.1:41539 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1598757 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598758 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598760 T4391 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@51d9c781
name:ZooKeeperConnection Watcher:127.0.0.1:41539 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1598760 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598760 T4315 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1598761 T4315 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1598764 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598764 T4392 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598765 T4395 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@47113641
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1598765 T4392 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598765 T4396 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5d3cddf9
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1598765 T4392 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1598765 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598766 T4315 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1598766 T4392 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1598767 T4315 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1598768 T4392 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1598768 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1598769 T4392 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1598770 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1598770 T4392 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:41539_solr
[junit4] 2> 1598770 T4392 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1598771 T4392 oasc.Overseer.start Overseer
(id=92326959601680387-127.0.0.1:41539_solr-n_0000000000) starting
[junit4] 2> 1598772 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1598772 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1598774 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1598775 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1598777 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1598778 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1598780 T4392 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1598783 T4392 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1598783 T4399 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1598783 T4392 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 1598784 T4398 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1598784 T4398 oasc.Overseer$ClusterStateUpdater.amILeader
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java: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.amILeader(Overseer.java:606)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:211)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1598785 T4398 oasc.Overseer$ClusterStateUpdater.amILeader
According to ZK I (id=92326959601680387-127.0.0.1:41539_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 1598785 T4392 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1598785 T4398 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:41539_solr
[junit4] 2> 1598786 T4403
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1598789 T4402 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7b534180
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1598789 T4392 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1598790 T4392 oasc.Overseer.close Overseer
(id=92326959601680387-127.0.0.1:41539_solr-n_0000000000) closing
[junit4] 2> 1598790 T4392 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1598791 T4399 oasc.OverseerCollectionProcessor.run ERROR
Unable to prioritize overseer
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /roles.json
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:256)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:253)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:253)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:411)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:258)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1598793 T4392 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1598794 T4392 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:41539_solr
[junit4] 2> 1598794 T4392 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1598796 T4392 oasc.Overseer.start Overseer
(id=92326959601680389-127.0.0.1:41539_solr-n_0000000001) starting
[junit4] 2> 1598801 T4392 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1598801 T4405 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1598802 T4404 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1598803 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1598803 T4404
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1598803 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1598805 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1598805 T4397 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> 1599274 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1599278 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1599280 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1599282 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1599283 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1599283 T4404 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1599284 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1599284 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1599285 T4397 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> 1599285 T4409 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@149ee47a
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1599285 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1599286 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1599287 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 1599291 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1599291 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1599293 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1599293 T4404 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1599297 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1599298 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1599299 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=1
[junit4] 2> 1599299 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1599403 T4410 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1599403 T4397 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1599798 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1599809 T4411 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> 1599810 T4410 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1599815 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1599921 T4410 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> 1601309 T4397 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> 1601311 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1601312 T4413 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3ecde5d name:ZooKeeperConnection
Watcher:127.0.0.1:41539/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1601312 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1601313 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1601315 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1601318 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1601318 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1601319 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601319 T4404 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601322 T4414 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1601322 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1601322 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1601323 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601323 T4404 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601325 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1601326 T4315 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1601327 T4416 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3a346c72
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1601327 T4315 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1601328 T4315
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1601329 T4315 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 1601330 T4407 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1601331 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1601331 T4404 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601331 T4404 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601404 T4392 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 1601406 T4392 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1601408 T4419 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@474011af
name:ZooKeeperConnection Watcher:127.0.0.1:41539/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1601408 T4392 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1601408 T4392 oasc.Overseer.close Overseer
(id=92326959601680389-127.0.0.1:41539_solr-n_0000000001) closing
[junit4] 2> 1601408 T4404 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:41539_solr
[junit4] 2> 1601408 T4392 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1601410 T4420
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1601411 T4392 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1601413 T4392 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:41539_solr
[junit4] 2> 1601413 T4392 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1601414 T4392 oasc.Overseer.start Overseer
(id=92326959601680393-127.0.0.1:41539_solr-n_0000000002) starting
[junit4] 2> 1601419 T4392 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1601419 T4422 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1601421 T4421 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 1601421 T4421 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601421 T4421 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601422 T4417 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601422 T4414 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601423 T4421 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601423 T4421 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601423 T4414 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601423 T4417 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601425 T4417 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601425 T4414 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601426 T4421 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1601426 T4421 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601427 T4417 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601427 T4414 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1601427 T4421 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1601537 T4315 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1601537 T4424 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1601539 T4421 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1601539 T4421 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1601542 T4413 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@3aebb20f rejected from
java.util.concurrent.ThreadPoolExecutor@47f71501[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> 1601542 T4425 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
[...truncated too long message...]
ForConnected Client is connected to ZooKeeper
[junit4] 2> 1664053 T4315 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1664056 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1664059 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1664062 T4315 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1664064 T4315 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:46213_solr
[junit4] 2> 1664065 T4315 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1664068 T4315 oasc.Overseer.start Overseer
(id=92326963879215107-127.0.0.1:46213_solr-n_0000000000) starting
[junit4] 2> 1664070 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1664074 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1664078 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1664082 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1664086 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1664089 T4315 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1664095 T4315 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1664096 T5087 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1664098 T5086 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1664101 T5086 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> 1664101 T5086 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1664105 T5089 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1664105 T5090 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> 1664153 T5089 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1664156 T5086 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> 1664156 T5086 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 1664156 T5086 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1664261 T5090 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> 1664307 T4315 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46213 46213
[junit4] 2> 1664891 T5073 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46213 46213
[junit4] 2> 1664893 T4315 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 1664894 T4315 oasc.Overseer.close Overseer
(id=92326963879215107-127.0.0.1:46213_solr-n_0000000000) closing
[junit4] 2> 1664894 T5086 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:46213_solr
[junit4] 2> 1664895 T5091
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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1667897 T4315 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-20505546D23B741-001
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=DefaultSimilarity, locale=fr_CH, timezone=America/New_York
[junit4] 2> NOTE: Linux 3.13.0-34-generic amd64/Oracle Corporation
1.7.0_67 (64-bit)/cpus=8,threads=1,free=97132456,total=330399744
[junit4] 2> NOTE: All tests run in this JVM:
[TriLevelCompositeIdRoutingTest, TestDistributedMissingSort,
DirectSolrSpellCheckerTest, TestRTGBase, ZkControllerTest, TestRangeQuery,
TestSolrDeletionPolicy2, TestCodecSupport, TestFieldTypeResource,
DistributedExpandComponentTest, SharedFSAutoReplicaFailoverUtilsTest,
TestShortCircuitedRequests, ZkNodePropsTest, NoCacheHeaderTest,
TestAnalyzedSuggestions, HighlighterTest, AddBlockUpdateTest, EnumFieldTest,
TestSolr4Spatial, JSONWriterTest, FieldFacetExtrasTest, TestTrie,
EchoParamsTest, MinimalSchemaTest, TermsComponentTest,
OpenExchangeRatesOrgProviderTest, TestArbitraryIndexDir, TestStressVersions,
ModifyConfFileTest, FileUtilsTest, DeleteShardTest, TestFastWriter,
SpellingQueryConverterTest, DistribCursorPagingTest, MBeansHandlerTest,
PathHierarchyTokenizerFactoryTest, SpellPossibilityIteratorTest,
HighlighterConfigTest, XmlUpdateRequestHandlerTest, ZkCLITest,
ShardRoutingTest, TestSurroundQueryParser, OverseerCollectionProcessorTest,
SolrIndexSplitterTest, TestRandomDVFaceting, ResponseHeaderTest,
DocValuesMultiTest, PeerSyncTest, SpellCheckCollatorTest, TestFastLRUCache,
TestExpandComponent, ExternalFileFieldSortTest, CoreAdminHandlerTest,
XsltUpdateRequestHandlerTest, TestBlendedInfixSuggestions, TestLRUCache,
DocValuesMissingTest, DateRangeFieldTest, TestJmxIntegration,
HdfsDirectoryTest, ResponseLogComponentTest, ChaosMonkeyNothingIsSafeTest,
TestLuceneMatchVersion, AsyncMigrateRouteKeyTest, TestSystemIdResolver,
SharedFSAutoReplicaFailoverTest, TestHashPartitioner, AtomicUpdatesTest,
QueryFacetTest, TestModifyConfFiles, TestDocumentBuilder,
TestSolrCoreProperties, PingRequestHandlerTest, TestRestManager,
RecoveryZkTest, TestCloudPivotFacet, StatelessScriptUpdateProcessorFactoryTest,
InfoHandlerTest, TestSearchPerf, SolrCmdDistributorTest, HdfsLockFactoryTest,
TestFoldingMultitermQuery, NotRequiredUniqueKeyTest,
TestManagedSchemaFieldResource, SignatureUpdateProcessorFactoryTest,
TestMiniSolrCloudCluster, RegexBoostProcessorTest, ShowFileRequestHandlerTest,
StandardRequestHandlerTest, TestRemoteStreaming,
TestCursorMarkWithoutUniqueKey, HdfsRecoveryZkTest,
TestWordDelimiterFilterFactory, TestMaxScoreQueryParser,
TestShardHandlerFactory, TestSolr4Spatial2, TestSolrIndexConfig,
SSLMigrationTest, TestSolrDeletionPolicy1,
DistributedQueryComponentOptimizationTest, TestChildDocTransformer,
IndexBasedSpellCheckerTest, SuggesterTSTTest, BasicDistributedZkTest,
SyncSliceTest, OverseerTest]
[junit4] Completed on J0 in 79.69s, 9 tests, 1 error <<< FAILURES!
[...truncated 647 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:485: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:465: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:48: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:494:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1342:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:957:
There were test failures: 430 suites, 1783 tests, 1 error, 40 ignored (19
assumptions)
Total time: 85 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0_67
-XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
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]
