Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/2069/
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration
node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because
creating the ephemeral registration node in ZooKeeper failed
at
__randomizedtesting.SeedInfo.seed([A488D6E45BB4A02F:A080591749114F0E]:0)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java: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.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
... 48 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 49 more
Build Log:
[...truncated 11086 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-A488D6E45BB4A02F-001/init-core-data-001
[junit4] 2> 398180 T2266 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (true)
[junit4] 2> 398180 T2266 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 398180 T2266 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 398184 T2266 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignment
[junit4] 2> 398185 T2266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 398186 T2267 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 398285 T2266 oasc.ZkTestServer.run start zk server on
port:30294
[junit4] 2> 398287 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 398290 T2273 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4daa089c
name:ZooKeeperConnection Watcher:127.0.0.1:30294 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398291 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 398293 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 398295 T2275 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@23f844d9
name:ZooKeeperConnection Watcher:127.0.0.1:30294 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398295 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 398295 T2266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 398299 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 398300 T2277 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@c6ea03f name:ZooKeeperConnection
Watcher:127.0.0.1:30294/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 398300 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 398301 T2266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 398303 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 398304 T2279 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5e9e73c2
name:ZooKeeperConnection Watcher:127.0.0.1:30294/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398304 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 398305 T2266 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 398306 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 398308 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 398310 T2266 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 398312 T2266 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:30294_solr
[junit4] 2> 398312 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 398314 T2266 oasc.Overseer.start Overseer
(id=92324640360235011-127.0.0.1:30294_solr-n_0000000000) starting
[junit4] 2> 398316 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 398318 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 398321 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 398324 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 398326 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 398329 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 398334 T2266 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 398334 T2281 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 398335 T2266 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 398336 T2280 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 398337 T2266 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 398339 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 398342 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 398343 T2284 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7cc29797
name:ZooKeeperConnection Watcher:127.0.0.1:30294/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 398343 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 398344 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 398347 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 398351 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 398353 T2280 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> 398353 T2280
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 398353 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 398356 T2285 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> 398356 T2286 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> 398852 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 398860 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 398865 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 398870 T2280 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> 398870 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 398870 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 398872 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 398873 T2285 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> 398873 T2286 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> 399366 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 399372 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 399376 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 399381 T2280 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> 399381 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 399382 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 399384 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 399385 T2285 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> 399385 T2286 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> 399878 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 399885 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 399889 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 399894 T2280 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> 399894 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 399894 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 399896 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 399897 T2285 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> 399897 T2286 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> 400390 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 400397 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 400399 T2280 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> 400400 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 400400 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 400503 T2286 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> 400503 T2285 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> 400898 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 400905 T2287 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 400907 T2280 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> 400907 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 400908 T2280 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 401011 T2285 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> 401011 T2286 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> 401405 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 401413 T2284 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@1a940965 rejected from
java.util.concurrent.ThreadPoolExecutor@6cf4d384[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> 401413 T2288 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> 402913 T2285 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> 402917 T2266 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:30294 30294
[junit4] 2> 403143 T2267 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:30294 30294
[junit4] 2> 403144 T2266 oas.SolrTestCaseJ4.tearDown ###Ending
testShardAssignment
[junit4] 2> 403145 T2266 oasc.Overseer.close Overseer
(id=92324640360235011-127.0.0.1:30294_solr-n_0000000000) closing
[junit4] 2> 403145 T2280 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:30294_solr
[junit4] 2> 403147 T2290
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 403154 T2266 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 403155 T2266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 403155 T2291 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 403255 T2266 oasc.ZkTestServer.run start zk server on
port:30300
[junit4] 2> 403256 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 403259 T2297 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@56c2dbc8
name:ZooKeeperConnection Watcher:127.0.0.1:30300 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 403260 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 403262 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 403263 T2299 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7dec14cb
name:ZooKeeperConnection Watcher:127.0.0.1:30300 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 403263 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 403264 T2266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 403267 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 403268 T2301 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@74524b1b
name:ZooKeeperConnection Watcher:127.0.0.1:30300/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 403269 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 403269 T2266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 403271 T2266 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 403273 T2266 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 403274 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 403277 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 403278 T2303 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7c6c993d
name:ZooKeeperConnection Watcher:127.0.0.1:30300/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 403278 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 403280 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 403282 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 403284 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 403286 T2307 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@50fe1b9b
name:ZooKeeperConnection Watcher:127.0.0.1:30300/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 403286 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 403286 T2266 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 403287 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 403289 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 403291 T2266 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 403293 T2266 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:30300_solr
[junit4] 2> 403293 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 403295 T2266 oasc.Overseer.start Overseer
(id=92324640685883396-127.0.0.1:30300_solr-n_0000000000) starting
[junit4] 2> 403296 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 403299 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 403302 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 403304 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 403307 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 403310 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 403314 T2266 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 403315 T2309 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 403316 T2308 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 404318 T2311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 404320 T2308 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 404320 T2308
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 404321 T2308 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 404323 T2305 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> 404323 T2304 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> 404818 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 404826 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 404831 T2311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 404834 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 404836 T2308 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 404836 T2308 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 404838 T2311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 404839 T2304 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> 404839 T2305 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> 405317 T2309 oasc.OverseerCollectionProcessor.amILeader
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:272)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 405318 T2309 oasc.OverseerCollectionProcessor.amILeader
According to ZK I (id=92324640685883396-127.0.0.1:30300_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 405893 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 405899 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 405901 T2313 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1bb68807
name:ZooKeeperConnection Watcher:127.0.0.1:30300/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 405901 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 405901 T2266 oasc.Overseer.close Overseer
(id=92324640685883396-127.0.0.1:30300_solr-n_0000000000) closing
[junit4] 2> 405902 T2308 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:30300_solr
[junit4] 2> 405902 T2266 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 405903 T2314
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 405905 T2266 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 405906 T2266 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:30300_solr
[junit4] 2> 405907 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 405909 T2266 oasc.Overseer.start Overseer
(id=92324640685883397-127.0.0.1:30300_solr-n_0000000001) starting
[junit4] 2> 405917 T2266 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 405918 T2316 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 405919 T2315 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 405922 T2315 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 405922 T2315 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 405924 T2318 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 405925 T2304 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> 405925 T2305 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> 405978 T2318 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 405978 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 405983 T2266 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92324640685883395-node1_core1-n_0000000002
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at
org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 405985 T2319 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 405984 T2315 oasc.SolrException.log ERROR Problem cleaning up
collection in
zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException:
KeeperErrorCode = Directory not empty for
/collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:189)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:670)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1104)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:362)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:244)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 405983 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 405986 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 405990 T2318 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 405991 T2315 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 406094 T2319 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> 406094 T2305 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> 406989 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 406989 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 407993 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 407993 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 408996 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 408997 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 409999 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 410000 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 411002 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 411003 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 412005 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 412006 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 413008 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 413009 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 414011 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 414012 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 415014 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 415015 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 416018 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 416018 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 417021 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 417021 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 418024 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 418025 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 419027 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 419028 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 420030 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 420031 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 421033 T2304 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 421034 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 421036 T2304 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.solr.common.SolrException: Could not register as the leader because
creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java: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> Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] 2> ... 10 more
[junit4] 2> Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 422538 T2304 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 422542 T2266 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:30300 30300
[junit4] 2> 423673 T2291 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:30300 30300
[junit4] 2> 423674 T2266 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 423675 T2266 oasc.Overseer.close Overseer
(id=92324640685883397-127.0.0.1:30300_solr-n_0000000001) closing
[junit4] 2> 423675 T2315 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:30300_solr
[junit4] 2> 423677 T2320
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=A488D6E45BB4A02F
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sk
-Dtests.timezone=Etc/GMT+11 -Dtests.file.encoding=US-ASCII
[junit4] ERROR 20.6s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not
register as the leader because creating the ephemeral registration node in
ZooKeeper failed
[junit4] > at
__randomizedtesting.SeedInfo.seed([A488D6E45BB4A02F:A080591749114F0E]:0)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] > at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] > at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] > ... 48 more
[junit4] > Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
[junit4] > at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 49 more
[junit4] 2> 423767 T2266 oas.SolrTestCaseJ4.setUp ###Starting
testShardLeaderChange
[junit4] 2> 423768 T2266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 423769 T2321 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 423869 T2266 oasc.ZkTestServer.run start zk server on
port:11446
[junit4] 2> 423870 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423873 T2327 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2f15acf name:ZooKeeperConnection
Watcher:127.0.0.1:11446/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 423873 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423874 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423876 T2329 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7b23bca8
name:ZooKeeperConnection Watcher:127.0.0.1:11446 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 423876 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423878 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423879 T2331 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@19e558f6
name:ZooKeeperConnection Watcher:127.0.0.1:11446 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 423880 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423880 T2266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 423883 T2266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 423887 T2332 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423887 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423888 T2335 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4d1fffbb
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 423888 T2332 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423888 T2336 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6fce758b
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 423889 T2332 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 423889 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423890 T2332 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 423890 T2266 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 423892 T2332 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 423892 T2266 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 423894 T2332 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 423894 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 423895 T2332 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:11446_solr
[junit4] 2> 423896 T2332 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 423896 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 423897 T2332 oasc.Overseer.start Overseer
(id=92324642036842499-127.0.0.1:11446_solr-n_0000000000) starting
[junit4] 2> 423899 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 423900 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 423902 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 423905 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 423907 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 423910 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 423913 T2332 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 423917 T2332 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 423918 T2339 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 423918 T2332 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 423920 T2332 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 423921 T2342 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3ea94c20
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 423921 T2332 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 423922 T2332 oasc.Overseer.close Overseer
(id=92324642036842499-127.0.0.1:11446_solr-n_0000000000) closing
[junit4] 2> 423922 T2339 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:412)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:259)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 423922 T2332 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 423925 T2332 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 423927 T2332 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:11446_solr
[junit4] 2> 423927 T2332 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 423929 T2332 oasc.Overseer.start Overseer
(id=92324642036842501-127.0.0.1:11446_solr-n_0000000001) starting
[junit4] 2> 423937 T2332 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 423938 T2344 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 423939 T2343 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 423941 T2343 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> 423942 T2343
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 423942 T2343 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 423944 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 423945 T2337 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> 424402 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 424410 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 424414 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 424416 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 424419 T2343 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> 424420 T2343 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 424421 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 424422 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 424423 T2348 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3bb48bd7
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 424423 T2337 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> 424423 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 424425 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 424427 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 424431 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 424431 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 424433 T2343 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> 424433 T2343 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 424438 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 424439 T2343 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> 424439 T2343 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=1
[junit4] 2> 424439 T2343 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 424543 T2337 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> 424543 T2349 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> 424938 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 424945 T2336 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@73015c0f rejected from
java.util.concurrent.ThreadPoolExecutor@5e4317c5[Shutting down, pool size = 2,
active threads = 2, queued tasks = 0, completed tasks = 5]
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
[junit4] 2> at
java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java: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> 424945 T2350 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> 424946 T2349 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 424951 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 425056 T2349 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> 426444 T2337 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 426447 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 426448 T2352 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7af38db4
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 426448 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 426450 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 426452 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 426455 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 426455 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 426457 T2343 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> 426457 T2343 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426461 T2353 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 426462 T2346 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 426462 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 426463 T2343 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> 426463 T2343 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426463 T2332 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 426465 T2332 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 426466 T2355 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@28b612e1
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 426466 T2332 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 426466 T2332 oasc.Overseer.close Overseer
(id=92324642036842501-127.0.0.1:11446_solr-n_0000000001) closing
[junit4] 2> 426467 T2343 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:11446_solr
[junit4] 2> 426467 T2332 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 426468 T2356
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 426468 T2332 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 426469 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 426470 T2358 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2cf2a36e
name:ZooKeeperConnection Watcher:127.0.0.1:11446/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 426470 T2332 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:11446_solr
[junit4] 2> 426470 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 426470 T2332 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 426471 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 426472 T2332 oasc.Overseer.start Overseer
(id=92324642036842504-127.0.0.1:11446_solr-n_0000000002) starting
[junit4] 2> 426473 T2266 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 426476 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 426480 T2332 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 426480 T2361 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 426482 T2360 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 426482 T2360 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> 426483 T2360 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426483 T2353 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> 426483 T2359 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> 426485 T2360 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> 426485 T2360 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426486 T2359 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> 426486 T2353 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> 426499 T2360 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 426501 T2360 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> 426501 T2360 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426503 T2363 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 426506 T2360 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> 426506 T2360 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426508 T2363 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 426509 T2359 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> 426509 T2353 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> 426685 T2266 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 426685 T2363 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 426687 T2360 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> 426687 T2360 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 426691 T2364 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredExce
[...truncated too long message...]
path:null type:None
[junit4] 2> 469188 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 469188 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 469190 T3147 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1be54f54
name:ZooKeeperConnection Watcher:127.0.0.1:22416 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 469190 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 469192 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 469193 T3149 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7e433fe9
name:ZooKeeperConnection Watcher:127.0.0.1:22416 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 469193 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 469193 T2266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 469196 T2266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 469197 T2266 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 469199 T2266 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 469200 T2266
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 469202 T2266 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 469203 T3151 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2361b1af
name:ZooKeeperConnection Watcher:127.0.0.1:22416/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 469203 T2266 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 469204 T2266 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 469204 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 469206 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 469207 T2266 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 469208 T2266 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:22416_solr
[junit4] 2> 469209 T2266 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 469210 T2266 oasc.Overseer.start Overseer
(id=92324645006606339-127.0.0.1:22416_solr-n_0000000000) starting
[junit4] 2> 469211 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 469213 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 469215 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 469217 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 469219 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 469221 T2266 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 469224 T2266 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 469224 T3153 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 469225 T3152 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 469227 T3152 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> 469227 T3152 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 469229 T3155 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 469230 T3156 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> 469278 T3155 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 469279 T3152 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> 469279 T3152 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 469279 T3152 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 469382 T3156 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> 469432 T2266 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:22416 22416
[junit4] 2> 470671 T3139 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:22416 22416
[junit4] 2> 470672 T2266 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 470673 T2266 oasc.Overseer.close Overseer
(id=92324645006606339-127.0.0.1:22416_solr-n_0000000000) closing
[junit4] 2> 470673 T3152 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:22416_solr
[junit4] 2> 470674 T3157
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 473675 T2266 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-A488D6E45BB4A02F-001
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity,
locale=sk, timezone=Etc/GMT+11
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60
(64-bit)/cpus=16,threads=1,free=171820816,total=509607936
[junit4] 2> NOTE: All tests run in this JVM: [TestDistributedGrouping,
MBeansHandlerTest, TestRealTimeGet, HardAutoCommitTest, BasicDistributedZkTest,
TestComplexPhraseQParserPlugin, TestPivotHelperCode, DocumentBuilderTest,
TestDistributedMissingSort, TestReloadAndDeleteDocs,
ParsingFieldUpdateProcessorsTest, OverseerTest]
[junit4] Completed on J0 in 75.52s, 9 tests, 1 error <<< FAILURES!
[...truncated 1221 lines...]
BUILD FAILED
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:485:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:465:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:48:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/extra-targets.xml:37:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:494:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1343:
The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:958:
There were test failures: 419 suites, 1733 tests, 1 error, 53 ignored (19
assumptions)
Total time: 133 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-4.x-Java7 #2065
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 193179332 bytes
Compression is 0.0%
Took 36 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
