Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10923/
Java: 64bit/jdk1.7.0_65 -XX:-UseCompressedOops -XX:+UseParallelGC
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([3176A36987B7475C:357E2C9A9512A87D]:0)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
... 47 more
Build Log:
[...truncated 11490 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-3176A36987B7475C-001/init-core-data-001
[junit4] 2> 1471889 T4101 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 1471889 T4101 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1471889 T4101 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1471891 T4101 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 1471892 T4101 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1471892 T4102 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1471992 T4101 oasc.ZkTestServer.run start zk server on
port:47577
[junit4] 2> 1471993 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1471995 T4108 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@42ceff5d
name:ZooKeeperConnection Watcher:127.0.0.1:47577 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1471995 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1471997 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1471998 T4110 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6b23e032
name:ZooKeeperConnection Watcher:127.0.0.1:47577 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1471998 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1471998 T4101 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1472002 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1472003 T4112 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@69cd7367
name:ZooKeeperConnection Watcher:127.0.0.1:47577/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472003 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1472004 T4101 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1472006 T4101 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1472009 T4101 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1472011 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1472014 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1472015 T4114 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@18ef00c7
name:ZooKeeperConnection Watcher:127.0.0.1:47577/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472015 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1472017 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1472020 T4101 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1472024 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1472025 T4118 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4cb953b5
name:ZooKeeperConnection Watcher:127.0.0.1:47577/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472025 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1472026 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1472029 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1472032 T4101 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:47577_solr
[junit4] 2> 1472033 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1472035 T4101 oasc.Overseer.start Overseer
(id=92189487808446468-127.0.0.1:47577_solr-n_0000000000) starting
[junit4] 2> 1472037 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1472041 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1472044 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1472047 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1472050 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1472054 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1472058 T4120 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1472059 T4119 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1473061 T4121 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1473064 T4119 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1473065 T4119 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> 1473065 T4119
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1473065 T4119 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1473068 T4121 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1473069 T4115 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> 1473069 T4116 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> 1473561 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1473571 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1473577 T4121 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1473578 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1473579 T4119 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1473581 T4121 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1473581 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1473582 T4119 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> 1473582 T4119 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1473584 T4121 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1473686 T4115 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> 1473686 T4116 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> 1474060 T4120 oasc.OverseerCollectionProcessor.run WARN
Overseer cannot talk to ZK
[junit4] 2> 1474740 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1474749 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1474750 T4123 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@656a3e7 name:ZooKeeperConnection
Watcher:127.0.0.1:47577/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1474750 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1474751 T4119 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:47577_solr
[junit4] 2> 1474752 T4124
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1474755 T4101 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:47577_solr
[junit4] 2> 1474755 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1474756 T4101 oasc.Overseer.start Overseer
(id=92189487808446469-127.0.0.1:47577_solr-n_0000000001) starting
[junit4] 2> 1474765 T4126 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1474766 T4125 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1474768 T4125 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1474768 T4125 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> 1474769 T4125 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1474770 T4127 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1474771 T4115 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> 1474771 T4116 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> 1474825 T4127 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1474825 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1474827 T4125 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1474830 T4101 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92189487808446467-node1_core1-n_0000000001
[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:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.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:155)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java: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> 1474830 T4116 oasc.LeaderElector.checkIfIamLeader WARN Our
node is no longer in line to be leader
[junit4] 2> 1474831 T4128 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1474831 T4125 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:184)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:181)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:181)
[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:660)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:660)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1094)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:359)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1474832 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1474833 T4127 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1474834 T4127 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1474835 T4125 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1474836 T4127 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1474938 T4128 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> 1474938 T4115 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> 1475834 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1476839 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1477841 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1478846 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1479849 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1480851 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1481854 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1482856 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1483859 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1484861 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1485864 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1486867 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1487869 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1488872 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1489874 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1489879 T4101 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:47577 47577
[junit4] 2> 1490576 T4102 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:47577 47577
[junit4] 2> 1490578 T4101 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 1490579 T4125 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:47577_solr
[junit4] 2> 1490581 T4129
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=3176A36987B7475C
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=is_IS
-Dtests.timezone=America/St_Vincent -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 18.7s 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([3176A36987B7475C:357E2C9A9512A87D]:0)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
[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:155)
[junit4] > at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
[junit4] > at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] > ... 47 more
[junit4] 2> 1490591 T4101 oas.SolrTestCaseJ4.setUp ###Starting
testBadQueueItem
[junit4] 2> 1490592 T4101 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1490593 T4130 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1490692 T4101 oasc.ZkTestServer.run start zk server on
port:54210
[junit4] 2> 1490693 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1490695 T4136 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5e4fd724
name:ZooKeeperConnection Watcher:127.0.0.1:54210 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1490695 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1490698 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1490699 T4138 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@355b93af
name:ZooKeeperConnection Watcher:127.0.0.1:54210 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1490699 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1490700 T4101 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1490704 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1490705 T4140 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@529011ca
name:ZooKeeperConnection Watcher:127.0.0.1:54210/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1490705 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1490705 T4101 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1490707 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1490708 T4142 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@79504891
name:ZooKeeperConnection Watcher:127.0.0.1:54210/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1490708 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1490709 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1490713 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1490718 T4101 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:54210_solr
[junit4] 2> 1490718 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1490720 T4101 oasc.Overseer.start Overseer
(id=92189489033969667-127.0.0.1:54210_solr-n_0000000000) starting
[junit4] 2> 1490722 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1490725 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1490728 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1490731 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1490736 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1490741 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1490748 T4144 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1490748 T4101 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1490748 T4143 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1490749 T4101 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1490751 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1490753 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1490754 T4146 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2d7e233a
name:ZooKeeperConnection Watcher:127.0.0.1:54210/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1490754 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1490755 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1490757 T4101 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1490760 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1490761 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1490762 T4143 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> 1490762 T4143
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1490762 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1490764 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1490764 T4147 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> 1490764 T4148 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> 1491260 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1491270 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1491275 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491276 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491277 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1491280 T4143 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> 1491281 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1491281 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1491283 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491385 T4147 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> 1491385 T4148 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> 1491777 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1491784 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1491788 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491789 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491789 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491790 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491790 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1491795 T4143 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> 1491795 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1491795 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1491799 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1491901 T4147 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> 1491901 T4148 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> 1492290 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1492298 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1492304 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492304 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492304 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492306 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1492309 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492411 T4148 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> 1492411 T4147 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> 1492456 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492456 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492456 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492458 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492458 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1492459 T4143
oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid
Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1492463 T4143
oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid
Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 1492465 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492466 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1492466 T4143
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 1492466 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1492468 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492570 T4148 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> 1492570 T4147 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> 1492959 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard3/election
[junit4] 2> 1492968 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard3
[junit4] 2> 1492971 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492971 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492971 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492972 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1492972 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1492975 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1492975 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1492975 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1492977 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493079 T4147 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> 1493079 T4148 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> 1493473 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard2/election
[junit4] 2> 1493479 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard2
[junit4] 2> 1493484 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493484 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493484 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493486 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493487 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1493489 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1493489 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1493489 T4143 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1493491 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493593 T4147 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> 1493594 T4148 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> 1493986 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard1/election
[junit4] 2> 1493994 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard1
[junit4] 2> 1493999 T4150 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493999 T4151 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1493999 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1494001 T4143 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1494004 T4149 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1494105 T4147 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> 1494105 T4148 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> 1495651 T4148 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1495653 T4101 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:54210 54210
[junit4] 2> 1496200 T4130 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:54210 54210
[junit4] 2> 1496202 T4101 oas.SolrTestCaseJ4.tearDown ###Ending
testBadQueueItem
[junit4] 2> 1496202 T4143 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:54210_solr
[junit4] 2> 1496203 T4152
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1496206 T4101 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1496207 T4101 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1496207 T4153 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1496307 T4101 oasc.ZkTestServer.run start zk server on
port:45402
[junit4] 2> 1496309 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1496310 T4159 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4d1ba727
name:ZooKeeperConnection Watcher:127.0.0.1:45402/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1496310 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1496311 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1496312 T4161 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1dfc6627
name:ZooKeeperConnection Watcher:127.0.0.1:45402 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1496312 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1496314 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1496315 T4163 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@55337213
name:ZooKeeperConnection Watcher:127.0.0.1:45402 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1496315 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1496315 T4101 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1496317 T4101 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1496318 T4101 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1496319 T4101 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1496320 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1496322 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1496324 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1496325 T4165 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@28f7071b
name:ZooKeeperConnection Watcher:127.0.0.1:45402/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1496325 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1496325 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1496326 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1496328 T4101 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:45402_solr
[junit4] 2> 1496329 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1496330 T4101 oasc.Overseer.start Overseer
(id=92189489401954307-127.0.0.1:45402_solr-n_0000000000) starting
[junit4] 2> 1496331 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1496333 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1496335 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1496337 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1496339 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1496342 T4167 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1496344 T4166 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1496345 T4166 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 1496345 T4166 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1496346 T4168 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> 1496348 T4166 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1496348 T4168 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> 1496349 T4166 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1496350 T4166 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1496351 T4166 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1496352 T4169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1496454 T4168 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> 1496546 T4101 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:45402 45402
[junit4] 2> 1497233 T4153 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:45402 45402
[junit4] 2> 1497234 T4101 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1497234 T4166 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:45402_solr
[junit4] 2> 1497245 T4170
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1497246 T4101 oas.SolrTestCaseJ4.setUp ###Starting
testShardLeaderChange
[junit4] 2> 1497246 T4101 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1497247 T4171 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1497347 T4101 oasc.ZkTestServer.run start zk server on
port:49178
[junit4] 2> 1497348 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497350 T4177 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@38dfd2c name:ZooKeeperConnection
Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1497350 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497351 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497352 T4179 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@712c65a5
name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497352 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497354 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497355 T4181 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7bc7bd8c
name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497355 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497355 T4101 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1497357 T4101 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1497360 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497360 T4182 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497361 T4185 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7746ea97
name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497361 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497361 T4186 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@50d39cae
name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497361 T4182 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497361 T4101 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1497362 T4182 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1497363 T4101 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1497364 T4182 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1497365 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1497366 T4182 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:49178_solr
[junit4] 2> 1497366 T4101 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1497367 T4182 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1497368 T4182 oasc.Overseer.start Overseer
(id=92189489470046212-127.0.0.1:49178_solr-n_0000000000) starting
[junit4] 2> 1497369 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1497370 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1497371 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1497373 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1497375 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1497377 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1497379 T4182 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1497382 T4182 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 1497382 T4189 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1497383 T4182 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497384 T4191 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@57b8c486
name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497384 T4182 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497384 T4189 oasc.OverseerCollectionProcessor.amILeader
According to ZK I (id=92189489470046212-127.0.0.1:49178_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 1497385 T4189 oasc.SolrException.log ERROR
:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode
= Session expired for /overseer/collection-queue-work
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:285)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:99)
[junit4] 2> at
org.apache.solr.cloud.DistributedQueue.getTailId(DistributedQueue.java:483)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:241)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1497385 T4189 oasc.OverseerCollectionProcessor.run ERROR
Unable to prioritize overseer
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /roles.json
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:251)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:248)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:248)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:256)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1497386 T4182 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:49178_solr
[junit4] 2> 1497387 T4182 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1497388 T4182 oasc.Overseer.start Overseer
(id=92189489470046213-127.0.0.1:49178_solr-n_0000000001) starting
[junit4] 2> 1497393 T4193 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1497394 T4192 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1497395 T4192 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1497396 T4192 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> 1497396 T4192
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1497396 T4192 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1497398 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497399 T4187 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> 1497871 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1497877 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1497880 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497881 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497881 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1497881 T4192 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1497884 T4192 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> 1497884 T4192 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1497885 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1497885 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497886 T4196 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3cfab16b
name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1497886 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1497887 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1497888 T4101 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 1497891 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497891 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1497892 T4192 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> 1497892 T4192 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1497894 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1497896 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1497996 T4197 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> 1497996 T4187 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> 1498097 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1498100 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498101 T4198 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498101 T4199 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498103 T4192 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1498104 T4192 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> 1498104 T4192 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=1
[junit4] 2> 1498104 T4192 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1498107 T4199 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498209 T4197 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> 1498209 T4187 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> 1498601 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1498607 T4200 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:285)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1498607 T4201 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:285)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:282)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1498608 T4197 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1498611 T4199 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498612 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498611 T4198 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498613 T4192 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1498614 T4198 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1498716 T4197 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> 1500107 T4187 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1500108 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1500110 T4101 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1500112 T4203 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2ff8b6e1
name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1500112 T4101 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1500113 T4101
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1500114 T4101 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1500118 T4198 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500118 T4199 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500118 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1500118 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500119 T4192 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1500119 T4192 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> 1500119 T4192 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1500121 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500123 T4205 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1500123 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500123 T4101 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1500123 T4192 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> 1500124 T4192 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1500125 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500126 T4194 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1500127 T4101 oascc.ConnectionManager.waitForC
[...truncated too long message...]
ct
[junit4] 2> 1556470 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1556475 T4101 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:33172_solr
[junit4] 2> 1556475 T4101 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1556478 T4101 oasc.Overseer.start Overseer
(id=92189493342699523-127.0.0.1:33172_solr-n_0000000000) starting
[junit4] 2> 1556480 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1556484 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1556487 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1556490 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1556493 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1556497 T4101 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1556503 T4991 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1556504 T4990 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1556505 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1556507 T4990 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1556507 T4990 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> 1556508 T4990 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1556511 T4992 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1556512 T4993 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> 1556557 T4101 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1556559 T4992 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1556562 T4990 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1556563 T4990 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> 1556563 T4990 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 1556563 T4990 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1556566 T4992 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1556668 T4993 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> 1556713 T4101 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:33172 33172
[junit4] 2> 1557276 T4977 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:33172 33172
[junit4] 2> 1557279 T4101 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 1557280 T4990 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:33172_solr
[junit4] 2> 1557281 T4994
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:302)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:299)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:317)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:289)
[junit4] 2>
[junit4] 2> 1560282 T4101 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-3176A36987B7475C-001
[junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{},
sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=is_IS,
timezone=America/St_Vincent
[junit4] 2> NOTE: Linux 3.13.0-32-generic amd64/Oracle Corporation
1.7.0_65 (64-bit)/cpus=8,threads=1,free=100285136,total=347078656
[junit4] 2> NOTE: All tests run in this JVM: [LeaderElectionTest,
HdfsWriteToMultipleCollectionsTest, IndexBasedSpellCheckerTest, RecoveryZkTest,
TestAnalyzedSuggestions, TestDocSet, UnloadDistributedZkTest,
TimeZoneUtilsTest, OverseerStatusTest, TestClassNameShortening, TestFaceting,
TestFileDictionaryLookup, TestInfoStreamLogging, CoreAdminHandlerTest,
SyncSliceTest, HdfsBasicDistributedZk2Test, SpellCheckComponentTest,
ZkControllerTest, DeleteInactiveReplicaTest, TestSolrCoreProperties,
CursorMarkTest, JSONWriterTest, TestReload, NotRequiredUniqueKeyTest,
FieldMutatingUpdateProcessorTest, TestDynamicFieldCollectionResource,
DocExpirationUpdateProcessorFactoryTest, FastVectorHighlighterTest,
HighlighterMaxOffsetTest, TestManagedResource,
PathHierarchyTokenizerFactoryTest, XmlUpdateRequestHandlerTest,
TestOverriddenPrefixQueryForCustomFieldType, QueryResultKeyTest, TestSolrJ,
TestSort, TestCoreDiscovery, StatelessScriptUpdateProcessorFactoryTest,
ReturnFieldsTest, TestFastLRUCache, OverseerCollectionProcessorTest,
TestChildDocTransformer, BadIndexSchemaTest, DirectSolrSpellCheckerTest,
TestTolerantSearch, TestSolrXmlPersistence, SSLMigrationTest,
QueryEqualityTest, HighlighterTest, DocumentAnalysisRequestHandlerTest,
AbstractAnalyticsStatsTest, DistribDocExpirationUpdateProcessorTest,
CurrencyFieldOpenExchangeTest, CoreAdminCreateDiscoverTest, TestFieldResource,
TestStandardQParsers, TestBinaryResponseWriter, SolrCmdDistributorTest,
TestSolrDeletionPolicy2, TestComponentsName, DateFieldTest,
ResponseLogComponentTest, TestFieldTypeResource, TestRandomDVFaceting,
FileUtilsTest, TestManagedSynonymFilterFactory, FieldFacetTest,
CoreMergeIndexesAdminHandlerTest, TestFastOutputStream, AssignTest,
SolrXmlInZkTest, ExternalFileFieldSortTest, TestFieldTypeCollectionResource,
NoCacheHeaderTest, BasicDistributedZkTest, ShardRoutingTest,
RAMDirectoryFactoryTest, AnalyticsQueryTest, DirectUpdateHandlerTest,
TestExceedMaxTermLength, HdfsCollectionsAPIDistributedZkTest,
TestReplicationHandler, BasicFunctionalityTest, TestDefaultSearchFieldResource,
DocumentBuilderTest, TestSchemaSimilarityResource, PingRequestHandlerTest,
ReplicationFactorTest, TestStressVersions, TestCollationFieldDocValues,
MinimalSchemaTest, BlockCacheTest, TestSchemaResource,
SignatureUpdateProcessorFactoryTest, IndexSchemaTest,
TestComplexPhraseQParserPlugin, PeerSyncTest, TestPartialUpdateDeduplication,
EchoParamsTest, TestFastWriter, TermsComponentTest, TestReRankQParserPlugin,
BasicDistributedZk2Test, OverseerTest]
[junit4] Completed on J0 in 88.41s, 9 tests, 1 error <<< FAILURES!
[...truncated 771 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1298:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:922:
There were test failures: 422 suites, 1754 tests, 1 error, 39 ignored (18
assumptions)
Total time: 86 minutes 52 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.7.0_65
-XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
