Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10988/
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([B47403706B1EEDE7:B07C8C8379BB02C6]: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 11535 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-B47403706B1EEDE7-001/init-core-data-001
[junit4] 2> 1852695 T5168 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(true) and clientAuth (false)
[junit4] 2> 1852695 T5168 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1852695 T5168 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1852698 T5168 oas.SolrTestCaseJ4.setUp ###Starting
testStateChange
[junit4] 2> 1852699 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1852700 T5169 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1852800 T5168 oasc.ZkTestServer.run start zk server on
port:45454
[junit4] 2> 1852802 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1852804 T5175 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@55e0a3b2
name:ZooKeeperConnection Watcher:127.0.0.1:45454/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1852804 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1852806 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1852808 T5177 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@436ce76e
name:ZooKeeperConnection Watcher:127.0.0.1:45454 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1852808 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1852812 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1852814 T5179 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1edcf90b
name:ZooKeeperConnection Watcher:127.0.0.1:45454 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1852814 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1852814 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1852819 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1852822 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1852825 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1852826 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1852829 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1852830 T5181 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@478d9ad4
name:ZooKeeperConnection Watcher:127.0.0.1:45454/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1852830 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1852831 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1852833 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1852835 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:45454_solr
[junit4] 2> 1852835 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1852836 T5168 oasc.Overseer.start Overseer
(id=92249415034929155-127.0.0.1:45454_solr-n_0000000000) starting
[junit4] 2> 1852837 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1852838 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1852840 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1852843 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1852845 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1852848 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1852852 T5183 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1852853 T5182 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1852853 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1852854 T5182 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1852854 T5182 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> 1852854 T5182 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1852856 T5184 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1852856 T5185 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> 1852904 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1852906 T5184 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1852907 T5182 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1852908 T5182 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> 1852908 T5182 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 1852908 T5182 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1853011 T5185 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> 1853061 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:45454 45454
[junit4] 2> 1853776 T5169 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:45454 45454
[junit4] 2> 1853777 T5168 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 1853777 T5182 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:45454_solr
[junit4] 2> 1853779 T5186
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> 1853784 T5168 oas.SolrTestCaseJ4.setUp ###Starting
testDoubleAssignment
[junit4] 2> 1853784 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1853785 T5187 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1853885 T5168 oasc.ZkTestServer.run start zk server on
port:44593
[junit4] 2> 1853886 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1853888 T5193 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@91a5982 name:ZooKeeperConnection
Watcher:127.0.0.1:44593/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1853888 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1853889 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1853890 T5195 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@166c9c22
name:ZooKeeperConnection Watcher:127.0.0.1:44593 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853890 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1853892 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1853893 T5197 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@59d9334a
name:ZooKeeperConnection Watcher:127.0.0.1:44593 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853893 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1853893 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1853895 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1853897 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1853898 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1853899 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1853901 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1853902 T5199 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@47c48b77
name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853902 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1853903 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1853904 T5168 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1853906 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1853907 T5203 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4cb8bf8d
name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1853908 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1853909 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1853910 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1853912 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:44593_solr
[junit4] 2> 1853912 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1853913 T5168 oasc.Overseer.start Overseer
(id=92249415106035716-127.0.0.1:44593_solr-n_0000000000) starting
[junit4] 2> 1853914 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1853916 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1853917 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1853919 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1853921 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1853922 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1853925 T5205 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1853926 T5204 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1853927 T5206 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1853928 T5204 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1853929 T5204 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> 1853929 T5204
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1853929 T5204 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1853931 T5200 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> 1853931 T5201 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> 1854428 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1854432 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1854435 T5206 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1854435 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1854438 T5204 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1854440 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1854441 T5208 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@48ac0e0a
name:ZooKeeperConnection Watcher:127.0.0.1:44593/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1854441 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1854443 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1854444 T5168 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1854447 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1854447 T5206 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1854448 T5204 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> 1854448 T5204 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1854450 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1854453 T5206 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1854556 T5201 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> 1854556 T5209 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> 1854557 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1854561 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:44593 44593
[junit4] 2> 1855145 T5187 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:44593 44593
[junit4] 2> 1855147 T5168 oas.SolrTestCaseJ4.tearDown ###Ending
testDoubleAssignment
[junit4] 2> 1855150 T5204 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:44593_solr
[junit4] 2> 1855158 T5210
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> 1855164 T5168 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1855164 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1855167 T5211 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1855268 T5168 oasc.ZkTestServer.run start zk server on
port:57440
[junit4] 2> 1855271 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1855274 T5217 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@526746f8
name:ZooKeeperConnection Watcher:127.0.0.1:57440/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1855274 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1855281 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1855282 T5219 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@bd9ebd4 name:ZooKeeperConnection
Watcher:127.0.0.1:57440 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1855282 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1855326 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1855326 T5221 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@231f079f
name:ZooKeeperConnection Watcher:127.0.0.1:57440 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1855328 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1855328 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1855331 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1855334 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1855335 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1855337 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1855339 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1855343 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1855344 T5223 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@148e01cc
name:ZooKeeperConnection Watcher:127.0.0.1:57440/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1855344 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1855346 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1855347 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1855357 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:57440_solr
[junit4] 2> 1855357 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1855359 T5168 oasc.Overseer.start Overseer
(id=92249415196803075-127.0.0.1:57440_solr-n_0000000000) starting
[junit4] 2> 1855360 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1855363 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1855366 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1855370 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1855387 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1855422 T5225 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1855428 T5224 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1855428 T5224 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 1855429 T5224 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> 1855432 T5224 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> 1855447 T5226 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> 1855447 T5224 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1855450 T5224 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1855450 T5224 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> 1855452 T5227 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1855452 T5226 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> 1855527 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:57440 57440
[junit4] 2> 1855964 T5211 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:57440 57440
[junit4] 2> 1855965 T5168 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1855965 T5224 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:57440_solr
[junit4] 2> 1855973 T5228
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> 1855979 T5168 oas.SolrTestCaseJ4.setUp ###Starting
testBadQueueItem
[junit4] 2> 1855980 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1855980 T5229 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1856080 T5168 oasc.ZkTestServer.run start zk server on
port:56054
[junit4] 2> 1856081 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1856084 T5235 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6ec88c20
name:ZooKeeperConnection Watcher:127.0.0.1:56054 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1856085 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1856087 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1856088 T5237 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7f10ade3
name:ZooKeeperConnection Watcher:127.0.0.1:56054 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1856088 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1856089 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1856092 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1856094 T5239 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1b3ede15
name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1856095 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1856095 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1856097 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1856099 T5241 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5b492853
name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1856099 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1856100 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1856102 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1856104 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:56054_solr
[junit4] 2> 1856104 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1856105 T5168 oasc.Overseer.start Overseer
(id=92249415249952771-127.0.0.1:56054_solr-n_0000000000) starting
[junit4] 2> 1856106 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1856108 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1856110 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1856111 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1856113 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1856115 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1856118 T5243 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1856118 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1856118 T5242 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1856120 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1856121 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1856122 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1856124 T5245 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3cc5a9b7
name:ZooKeeperConnection Watcher:127.0.0.1:56054/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1856124 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1856126 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1856127 T5168 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1856131 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1856132 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1856133 T5242 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> 1856133 T5242
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1856133 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1856135 T5247 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> 1856135 T5246 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> 1856631 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1856636 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1856639 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1856640 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1856642 T5242 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> 1856642 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1856642 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1856643 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1856745 T5247 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> 1856745 T5246 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> 1857140 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1857144 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1857147 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1857148 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1857150 T5242 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> 1857151 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1857151 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1857152 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1857152 T5247 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> 1857152 T5246 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> 1857649 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1857653 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1857656 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1857657 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1857759 T5247 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> 1857759 T5246 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> 1857807 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1857809 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1857809 T5242
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> 1857812 T5242
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> 1857814 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1857814 T5242 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> 1857814 T5242
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 1857815 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1857917 T5246 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> 1857917 T5247 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> 1858310 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard2/election
[junit4] 2> 1858315 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard2
[junit4] 2> 1858317 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1858318 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1858320 T5242 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> 1858320 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1858320 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1858321 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1858322 T5247 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> 1858322 T5246 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> 1858818 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard3/election
[junit4] 2> 1858825 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard3
[junit4] 2> 1858828 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1858831 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1858833 T5242 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> 1858833 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1858833 T5242 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1858835 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1858836 T5246 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> 1858837 T5247 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> 1859331 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard1/election
[junit4] 2> 1859335 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard1
[junit4] 2> 1859338 T5248 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1859339 T5242 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1859441 T5246 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> 1859442 T5247 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> 1859493 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:56054 56054
[junit4] 2> 1860062 T5229 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:56054 56054
[junit4] 2> 1860063 T5168 oas.SolrTestCaseJ4.tearDown ###Ending
testBadQueueItem
[junit4] 2> 1860063 T5242 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:56054_solr
[junit4] 2> 1860064 T5249
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> 1860069 T5168 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 1860070 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1860071 T5250 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1860171 T5168 oasc.ZkTestServer.run start zk server on
port:53631
[junit4] 2> 1860172 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1860174 T5256 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5e07df67
name:ZooKeeperConnection Watcher:127.0.0.1:53631 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1860175 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1860177 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1860178 T5258 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@530a6cf7
name:ZooKeeperConnection Watcher:127.0.0.1:53631 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1860178 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1860179 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1860182 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1860183 T5260 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4618f8ec
name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1860183 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1860183 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1860185 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1860186 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1860188 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1860190 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1860192 T5262 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@77245f80
name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1860192 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1860193 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1860195 T5168 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1860198 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1860199 T5266 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@14370a32
name:ZooKeeperConnection Watcher:127.0.0.1:53631/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1860200 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1860201 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1860203 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1860205 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:53631_solr
[junit4] 2> 1860206 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1860207 T5168 oasc.Overseer.start Overseer
(id=92249415517995012-127.0.0.1:53631_solr-n_0000000000) starting
[junit4] 2> 1860208 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1860210 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1860212 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1860213 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1860215 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1860217 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1860220 T5268 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1860221 T5267 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1861223 T5269 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1861224 T5267 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1861224 T5267 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> 1861224 T5267
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1861224 T5267 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1861226 T5263 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> 1861226 T5264 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> 1861723 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1861728 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1861731 T5269 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1861731 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1861732 T5267 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1861732 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1861733 T5267 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> 1861734 T5267 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1861735 T5269 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1861735 T5263 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> 1861735 T5264 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> 1862222 T5268 oasc.OverseerCollectionProcessor.amILeader
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java: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.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:269)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1862222 T5268 oasc.OverseerCollectionProcessor.amILeader
According to ZK I (id=92249415517995012-127.0.0.1:53631_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 1862788 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1862792 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1862793 T5271 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@42ba3ed name:ZooKeeperConnection
Watcher:127.0.0.1:53631/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1862793 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1862793 T5267 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:53631_solr
[junit4] 2> 1862795 T5272
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> 1862796 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:53631_solr
[junit4] 2> 1862796 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1862797 T5168 oasc.Overseer.start Overseer
(id=92249415517995013-127.0.0.1:53631_solr-n_0000000001) starting
[junit4] 2> 1862802 T5274 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1862803 T5273 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1862804 T5273 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1862804 T5273 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> 1862804 T5273 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1862806 T5275 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1862806 T5264 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> 1862806 T5263 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> 1862858 T5275 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1862858 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1862859 T5273 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1862861 T5168 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92249415517995011-node1_core1-n_0000000002
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java: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> 1862863 T5273 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> 1862863 T5264 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1862863 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1862863 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1862866 T5275 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1862867 T5273 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1862969 T5263 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> 1862969 T5264 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> 1863866 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1863866 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1864869 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1864869 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1865871 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1865871 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1866873 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1866874 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1867876 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1867876 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1868880 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1868880 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1869884 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1869884 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1870888 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1870888 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1871890 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1871890 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1872892 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1872893 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1873896 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1873896 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1874899 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1874899 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1875902 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1875902 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1876904 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1876905 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1877906 T5276 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1877907 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1877909 T5276 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.solr.common.SolrException: Could not register as the leader because
creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:144)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:204)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:457)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:411)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:398)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:136)
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] 2> ... 10 more
[junit4] 2>
[junit4] 2> 1877915 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:53631 53631
[junit4] 2> 1878480 T5250 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:53631 53631
[junit4] 2> 1878481 T5168 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 1878482 T5273 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:53631_solr
[junit4] 2> 1878484 T5277
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=B47403706B1EEDE7
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ms_MY
-Dtests.timezone=Africa/Juba -Dtests.file.encoding=UTF-8
[junit4] ERROR 18.4s 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([B47403706B1EEDE7:B07C8C8379BB02C6]: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> 1878509 T5168 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignmentBigger
[junit4] 2> 1878510 T5168 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1878511 T5278 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1878610 T5168 oasc.ZkTestServer.run start zk server on
port:44196
[junit4] 2> 1878611 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1878614 T5284 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@7d152f4e
name:ZooKeeperConnection Watcher:127.0.0.1:44196 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1878614 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1878617 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1878618 T5286 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3d668715
name:ZooKeeperConnection Watcher:127.0.0.1:44196 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1878618 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1878618 T5168 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1878627 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1878628 T5288 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@59cc1540
name:ZooKeeperConnection Watcher:127.0.0.1:44196/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1878628 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1878629 T5168 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1878631 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1878632 T5290 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@63a63081
name:ZooKeeperConnection Watcher:127.0.0.1:44196/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1878632 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1878633 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1878634 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1878636 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:44196_solr
[junit4] 2> 1878636 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1878638 T5168 oasc.Overseer.start Overseer
(id=92249416726478851-127.0.0.1:44196_solr-n_0000000000) starting
[junit4] 2> 1878639 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1878640 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1878642 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1878644 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1878646 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1878648 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1878651 T5292 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1878651 T5291 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1878651 T5168 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1878653 T5168 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1878653 T5168
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1878655 T5168 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1878656 T5294 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.Connection
[...truncated too long message...]
Manager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cd801b5
name:ZooKeeperConnection Watcher:127.0.0.1:46905/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1919240 T5168 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1919241 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1919242 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1919243 T5168 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:46905_solr
[junit4] 2> 1919243 T5168 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1919244 T5168 oasc.Overseer.start Overseer
(id=92249419387895812-127.0.0.1:46905_solr-n_0000000000) starting
[junit4] 2> 1919245 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1919247 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1919248 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1919249 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1919251 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1919252 T5168 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1919254 T5780 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1919255 T5779 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1919256 T5779 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1919257 T5779 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1919257 T5779
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6,
shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 1919257 T5779 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard8
[junit4] 2> 1919258 T5781 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1919259 T5775 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> 1919259 T5776 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> 1919755 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard8/election
[junit4] 2> 1919761 T5168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard8
[junit4] 2> 1919764 T5781 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1919764 T5168 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 1919767 T5168 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46905 46905
[junit4] 2> 1920359 T5762 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46905 46905
[junit4] 2> 1920360 T5168 oas.SolrTestCaseJ4.tearDown ###Ending
testPlaceholders
[junit4] 2> 1920360 T5779 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:46905_solr
[junit4] 2> 1920362 T5782
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> 1923363 T5168 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-B47403706B1EEDE7-001
[junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{},
sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ms_MY,
timezone=Africa/Juba
[junit4] 2> NOTE: Linux 3.13.0-32-generic amd64/Oracle Corporation
1.7.0_65 (64-bit)/cpus=8,threads=1,free=113406072,total=325058560
[junit4] 2> NOTE: All tests run in this JVM:
[OverseerCollectionProcessorTest, TestSolrJ, MoreLikeThisHandlerTest,
HdfsWriteToMultipleCollectionsTest, RecoveryZkTest, TestAddFieldRealTimeGet,
CoreMergeIndexesAdminHandlerTest, AbstractAnalyticsStatsTest,
TestDynamicFieldCollectionResource, NoCacheHeaderTest, TestFastOutputStream,
BadIndexSchemaTest, TestHighlightDedupGrouping, SSLMigrationTest,
TestOverriddenPrefixQueryForCustomFieldType, TestAnalyzedSuggestions,
HighlighterConfigTest, MBeansHandlerTest, TestFieldTypeResource,
TestSearcherReuse, QueryResultKeyTest, ExpressionTest, AddBlockUpdateTest,
DirectSolrSpellCheckerTest, TriLevelCompositeIdRoutingTest,
TestCloudManagedSchemaConcurrent, SolrCoreCheckLockOnStartupTest,
HdfsBasicDistributedZk2Test, TestExceedMaxTermLength, DOMUtilTest,
TestReplicationHandler, TestSolrIndexConfig, WordBreakSolrSpellCheckerTest,
TestLRUCache, TestLeaderElectionZkExpiry, SolrIndexSplitterTest,
PathHierarchyTokenizerFactoryTest, FieldMutatingUpdateProcessorTest,
DocValuesMultiTest, RequiredFieldsTest, FunctionTest, TestManagedSchema,
CoreAdminCreateDiscoverTest, TestCloudInspectUtil, TestInfoStreamLogging,
RegexBoostProcessorTest, TestBinaryResponseWriter, TestRandomDVFaceting,
TestDefaultSimilarityFactory, TestLuceneMatchVersion,
TestSuggestSpellingConverter, TestStressReorder, AnalyticsQueryTest,
TestFastWriter, TestComponentsName, StandardRequestHandlerTest,
BasicFunctionalityTest, ChangedSchemaMergeTest, TestCoreDiscovery,
AnalysisErrorHandlingTest, ClusterStateUpdateTest, ResponseHeaderTest,
TestJmxIntegration, NotRequiredUniqueKeyTest, TestReloadAndDeleteDocs,
TestManagedResourceStorage, MigrateRouteKeyTest,
HdfsCollectionsAPIDistributedZkTest, HdfsBasicDistributedZkTest,
SimpleFacetsTest, TestSolrDeletionPolicy1, EchoParamsTest, TestTrie,
TestManagedSynonymFilterFactory, FastVectorHighlighterTest,
TestChildDocTransformer, TestAnalyzeInfixSuggestions, PingRequestHandlerTest,
TestMissingGroups, TestDocBasedVersionConstraints, PluginInfoTest,
TestDefaultSearchFieldResource, SuggesterTSTTest, DisMaxRequestHandlerTest,
ShardRoutingTest, UpdateParamsTest, TestSchemaResource,
TestSurroundQueryParser, FieldFacetTest, TestCustomSort, TimeZoneUtilsTest,
ParsingFieldUpdateProcessorsTest, ReplicationFactorTest,
OpenExchangeRatesOrgProviderTest, TestReRankQParserPlugin, SolrXmlInZkTest,
TestFaceting, SuggesterWFSTTest, TestSolrXmlPersistence, TestCodecSupport,
SuggesterTest, SuggestComponentTest, TestRTGBase, TestFoldingMultitermQuery,
BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest,
CollectionsAPIDistributedZkTest, SyncSliceTest, OverseerTest]
[junit4] Completed on J0 in 70.70s, 9 tests, 1 error <<< FAILURES!
[...truncated 660 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:474: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:454: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml: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: 421 suites, 1761 tests, 1 error, 39 ignored (18
assumptions)
Total time: 87 minutes 55 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]
