Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/590/
2 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([53BB0B78D4E89FC5:57B3848BC64D70E4]: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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
... 48 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java: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:34)
... 49 more
FAILED: org.apache.solr.cloud.MultiThreadedOCPTest.testDistribSearch
Error Message:
We have a failed SPLITSHARD task
Stack Trace:
java.lang.AssertionError: We have a failed SPLITSHARD task
at
__randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:D25D8560A3B7FFF9]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125)
at
org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71)
at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11473 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-53BB0B78D4E89FC5-001/init-core-data-001
[junit4] 2> 132304 T483 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (true)
[junit4] 2> 132304 T483 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 132304 T483 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 132309 T483 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 132322 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 132331 T484 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 132531 T483 oasc.ZkTestServer.run start zk server on port:34561
[junit4] 2> 132866 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 132915 T485 oazs.NIOServerCnxn.doIO WARN Exception causing
close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
[junit4] 2> 134169 T490 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2338eb14
name:ZooKeeperConnection Watcher:127.0.0.1:34561/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 134169 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 134176 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 134179 T492 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@71ba2933
name:ZooKeeperConnection Watcher:127.0.0.1:34561 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 134179 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 134264 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 134266 T494 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@b224c45 name:ZooKeeperConnection
Watcher:127.0.0.1:34561 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 134267 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 134273 T483 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 134300 T483 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 134324 T483 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 134327 T483 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 134329 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 134420 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 134433 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 134435 T496 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@2f1cf161
name:ZooKeeperConnection Watcher:127.0.0.1:34561/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 134435 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 134443 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 134446 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 134476 T483 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:34561_solr
[junit4] 2> 134477 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 134480 T483 oasc.Overseer.start Overseer
(id=92213278593843203-127.0.0.1:34561_solr-n_0000000000) starting
[junit4] 2> 134508 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 134520 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 134524 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 134528 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 134551 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 134560 T498 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 134575 T497 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 134576 T497 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 134577 T497 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> 134641 T497 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> 134642 T499 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> 134645 T497 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 134648 T497 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 134649 T497 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> 134653 T500 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 134756 T499 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> 134770 T483 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34561 34561
[junit4] 2> 134889 T484 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34561 34561
[junit4] 2> 134890 T483 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 134891 T497 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:34561_solr
[junit4] 2> 134900 T483 oas.SolrTestCaseJ4.setUp ###Starting
testDoubleAssignment
[junit4] 2> 134902 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 134902 T502 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 134904 T501
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:316)
[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:288)
[junit4] 2>
[junit4] 2> 135002 T483 oasc.ZkTestServer.run start zk server on port:34567
[junit4] 2> 135003 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135007 T508 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@102d0abe
name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135007 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135008 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135009 T510 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@548dcd63
name:ZooKeeperConnection Watcher:127.0.0.1:34567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135010 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135012 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135014 T512 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@17373182
name:ZooKeeperConnection Watcher:127.0.0.1:34567 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135014 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135014 T483 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 135018 T483 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 135021 T483 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 135024 T483 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 135026 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 135035 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135037 T514 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@24ff9528
name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135037 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135039 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 135042 T483 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 135046 T515 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135046 T516 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135046 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135048 T518 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@40af72ba
name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135048 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135049 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 135052 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 135058 T483 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:34567_solr
[junit4] 2> 135058 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 135061 T483 oasc.Overseer.start Overseer
(id=92213278738284548-127.0.0.1:34567_solr-n_0000000000) starting
[junit4] 2> 135063 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 135068 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 135072 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 135076 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 135081 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 135086 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 135093 T520 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 135095 T519 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 135098 T519 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 135099 T519 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> 135099 T519 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection1 with shards [shard1]
[junit4] 2> 135111 T519 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 135115 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135116 T515 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> 135116 T516 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> 135598 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 135628 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 135636 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135636 T483 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 135638 T519 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 135639 T516 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 135639 T515 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 135641 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135643 T523 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3b702644
name:ZooKeeperConnection Watcher:127.0.0.1:34567/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135643 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135645 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 135648 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135648 T483 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 135652 T516 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135652 T524 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135654 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135654 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 135655 T519 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> 135656 T519 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 135659 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135662 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 135668 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135672 T521 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 135775 T524 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> 135775 T516 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> 135776 T483 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 135780 T516 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 135780 T524 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 135782 T483 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34567 34567
[junit4] 2> 135825 T502 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34567 34567
[junit4] 2> 135826 T483 oas.SolrTestCaseJ4.tearDown ###Ending
testDoubleAssignment
[junit4] 2> 135826 T519 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:34567_solr
[junit4] 2> 135827 T525
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:316)
[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:288)
[junit4] 2>
[junit4] 2> 135836 T483 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 135837 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 135837 T526 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 135937 T483 oasc.ZkTestServer.run start zk server on port:34574
[junit4] 2> 135938 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135950 T532 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@65c9a3b8
name:ZooKeeperConnection Watcher:127.0.0.1:34574 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135950 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135953 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135955 T534 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6c78440 name:ZooKeeperConnection
Watcher:127.0.0.1:34574 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 135955 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135956 T483 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 135960 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135962 T536 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@26ebec38
name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135962 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135962 T483 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 135965 T483 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 135968 T483 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 135970 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 135974 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135975 T538 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3852eabd
name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135976 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135977 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 135981 T483 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 135984 T539 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135984 T540 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 135985 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 135986 T542 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@40beb5f0
name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 135987 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 135988 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 135991 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 135996 T483 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:34574_solr
[junit4] 2> 135997 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 136000 T483 oasc.Overseer.start Overseer
(id=92213278799495172-127.0.0.1:34574_solr-n_0000000000) starting
[junit4] 2> 136002 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 136006 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 136010 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 136015 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 136019 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 136023 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 136030 T544 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 136032 T543 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 137034 T545 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 137036 T543 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 137037 T543 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> 137037 T543 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection1 with shards [shard1]
[junit4] 2> 137038 T543 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 137041 T545 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 137042 T539 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> 137042 T540 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> 137534 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 137545 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 137552 T545 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 137553 T483 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 137554 T543 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 137557 T545 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 137557 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 137560 T543 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> 137560 T543 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 137563 T545 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 137666 T539 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> 137666 T540 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> 138035 T544 oasc.OverseerCollectionProcessor.run WARN Overseer
cannot talk to ZK
[junit4] 2> 138722 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 138731 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 138733 T547 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5633c113
name:ZooKeeperConnection Watcher:127.0.0.1:34574/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 138733 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 138733 T543 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:34574_solr
[junit4] 2> 138734 T548
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:316)
[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:288)
[junit4] 2>
[junit4] 2> 138738 T483 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:34574_solr
[junit4] 2> 138738 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 138741 T483 oasc.Overseer.start Overseer
(id=92213278799495173-127.0.0.1:34574_solr-n_0000000001) starting
[junit4] 2> 138753 T550 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 138755 T549 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 138757 T549 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 138758 T549 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> 138759 T549 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 138762 T551 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 138763 T540 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> 138763 T539 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> 138817 T551 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 138817 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 138819 T549 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 138824 T483 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92213278799495171-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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 138827 T540 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 138828 T549 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:1100)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:358)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:240)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 138829 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 138829 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 138831 T551 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 138834 T551 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 138835 T549 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 138838 T551 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 138941 T539 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> 138941 T540 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> 139833 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 139833 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 140837 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 140838 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 141842 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 141842 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 142846 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 142847 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 143851 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 143852 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 144855 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 144856 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 145859 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 145860 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 146863 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 146864 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 147867 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 147869 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 148871 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 148872 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 149875 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 149876 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 150880 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 150880 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 151884 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 151884 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 152889 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 152889 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 153893 T552 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 153893 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 153897 T552 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.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] 2> ... 10 more
[junit4] 2> Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java: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:34)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 153899 T540 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 153900 T539 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 153903 T483 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34574 34574
[junit4] 2> 154022 T526 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:34574 34574
[junit4] 2> 154023 T483 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 154024 T549 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:34574_solr
[junit4] 2> 154025 T553
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:316)
[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:288)
[junit4] 2>
[junit4] 2> NOTE: download the large Jenkins line-docs file by running
'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=53BB0B78D4E89FC5
-Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true
-Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt
-Dtests.locale=ko_KR -Dtests.timezone=Indian/Antananarivo
-Dtests.file.encoding=UTF-8
[junit4] ERROR 18.3s 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([53BB0B78D4E89FC5:57B3848BC64D70E4]: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.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:131)
[junit4] > ... 48 more
[junit4] > Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java: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:34)
[junit4] > ... 49 more
[junit4] 2> 154115 T483 oas.SolrTestCaseJ4.setUp ###Starting
testBadQueueItem
[junit4] 2> 154116 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 154117 T554 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 154217 T483 oasc.ZkTestServer.run start zk server on port:17441
[junit4] 2> 154218 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 154221 T560 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4d2c47e9
name:ZooKeeperConnection Watcher:127.0.0.1:17441 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 154222 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 154224 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 154226 T562 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@427a26e2
name:ZooKeeperConnection Watcher:127.0.0.1:17441 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 154226 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 154226 T483 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 154230 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 154231 T564 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1a6bdb60
name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 154232 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 154232 T483 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 154235 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 154236 T566 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@64109ce7
name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 154236 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 154238 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 154240 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 154245 T483 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:17441_solr
[junit4] 2> 154245 T483 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 154247 T483 oasc.Overseer.start Overseer
(id=92213279997493251-127.0.0.1:17441_solr-n_0000000000) starting
[junit4] 2> 154250 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 154253 T483 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 154256 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 154260 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 154263 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 154267 T483 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 154273 T568 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 154274 T483 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 154274 T567 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 154276 T483 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 154278 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 154281 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 154283 T570 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6d471f2d
name:ZooKeeperConnection Watcher:127.0.0.1:17441/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 154283 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 154285 T483
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 154288 T483 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 154290 T571 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 154291 T572 oascc.ZkStateReader$3.process Updating live
nodes... (1)
[junit4] 2> 154293 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 154294 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 154295 T567 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> 154295 T567 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 154296 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 154299 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 154300 T571 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> 154300 T572 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> 154793 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 154803 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 154809 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 154811 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 154811 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 154815 T567 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> 154816 T567 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 154816 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 154818 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 154921 T572 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> 154921 T571 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> 155311 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 155319 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 155324 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155324 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155324 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155326 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155326 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 155330 T567 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> 155331 T567 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 155331 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 155333 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155436 T571 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> 155436 T572 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> 155826 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 155834 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 155840 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155840 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155840 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155841 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 155845 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155947 T572 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> 155947 T571 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> 155995 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155995 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155995 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155996 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 155997 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 155997 T567
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> 156001 T567
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> 156004 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156005 T567 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> 156005 T567 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 156005 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 156008 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156110 T571 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> 156110 T572 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> 156499 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard3/election
[junit4] 2> 156508 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard3
[junit4] 2> 156514 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156514 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156514 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156516 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156516 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 156521 T567 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> 156521 T567 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 156521 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 156524 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 156626 T571 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> 156626 T572 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> 157016 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard2/election
[junit4] 2> 157024 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard2
[junit4] 2> 157029 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157029 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157029 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157031 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157031 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 157035 T567 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> 157035 T567 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 157035 T567 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 157038 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157141 T572 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> 157141 T571 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> 157531 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leader_elect/shard1/election
[junit4] 2> 157539 T483 oascc.SolrZkClient.makePath makePath:
/collections/collection2/leaders/shard1
[junit4] 2> 157544 T574 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157544 T575 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157544 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157545 T567 oascc.ZkStateReader.updateClusterState Updating
cloud state from ZooKeeper...
[junit4] 2> 157548 T573 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 157651 T571 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> 157651 T572 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> 157699 T571 oascc.ZkStateReader$3.process Updating live
nodes... (0)
[junit4] 2> 157701 T483 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:17441 17441
[junit4] 2> 157875 T554 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:17441 17441
[junit4] 2> 157876 T483 oas.SolrTestCaseJ4.tearDown ###Ending
testBadQueueItem
[junit4] 2> 157876 T567 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:17441_solr
[junit4] 2> 157877 T576
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:316)
[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:288)
[junit4] 2>
[junit4] 2> 157884 T483 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignmentBigger
[junit4] 2> 157885 T483 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 157886 T577 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 157986 T483 oasc.ZkTestServer.run start zk server on port:25338
[junit4] 2> 157987 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 157990 T583 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@64cbff21
name:ZooKeeperConnection Watcher:127.0.0.1:25338 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 157991 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 157993 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 157994 T585 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6e353af0
name:ZooKeeperConnection Watcher:127.0.0.1:25338 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 157995 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 157995 T483 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 157999 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 158000 T587 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3cfd7642
name:ZooKeeperConnection Watcher:127.0.0.1:25338/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 158000 T483 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 158001 T483 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 158003 T483 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 158004 T589 oascc.ConnectionManager.pro
[...truncated too long message...]
ndex
[CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest2_shard1_replica1/data/index;done=false>>]
[junit4] 2> 3780374 T10355 oasc.CachingDirectoryFactory.close Closing
directory:
./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest2_shard1_replica1/data/index
[junit4] 2> 3780374 T10355 oasc.SolrCore.close
[ocptest_shardsplit_shard4_replica1] CLOSING SolrCore
org.apache.solr.core.SolrCore@853f143
[junit4] 2> 3780383 T10355 oasu.DirectUpdateHandler2.close closing
DirectUpdateHandler2{commits=0,autocommits=0,soft
autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 3780383 T10355 oasu.SolrCoreState.decrefSolrCoreState Closing
SolrCoreState
[junit4] 2> 3780384 T10355 oasu.DefaultSolrCoreState.closeIndexWriter
SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 3780384 T10355 oasu.DefaultSolrCoreState.closeIndexWriter
closing IndexWriter with IndexWriterCloser
[junit4] 2> 3780385 T10355 oasc.SolrCore.closeSearcher
[ocptest_shardsplit_shard4_replica1] Closing main searcher on request.
[junit4] 2> 3780385 T10355 oasc.CachingDirectoryFactory.close Closing
MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 3780385 T10355 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index
[CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index;done=false>>]
[junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.close Closing
directory:
./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data/index
[junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data
[CachedDir<<refCount=0;path=./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data;done=false>>]
[junit4] 2> 3780386 T10355 oasc.CachingDirectoryFactory.close Closing
directory:
./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001/tempDir-006/ocptest_shardsplit_shard4_replica1/data
[junit4] 2> 3780387 T11942 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:37404_nzjt%2Fpm
[junit4] 2> 3780388 T11944
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:316)
[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:288)
[junit4] 2>
[junit4] 2> 3781888 T10469 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 3781890 T10355 oejsh.ContextHandler.doStop stopped
o.e.j.s.ServletContextHandler{/nzjt/pm,null}
[junit4] 2> 3784332 T10355 oas.SolrTestCaseJ4.tearDown ###Ending
testDistribSearch
[junit4] 2> 3784334 T10355 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:21266 21266
[junit4] 2> 3784477 T10356 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:21266 21266
[junit4] 2> NOTE: download the large Jenkins line-docs file by running
'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=MultiThreadedOCPTest -Dtests.method=testDistribSearch
-Dtests.seed=53BB0B78D4E89FC5 -Dtests.multiplier=2 -Dtests.nightly=true
-Dtests.slow=true
-Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt
-Dtests.locale=ko -Dtests.timezone=Antarctica/Casey -Dtests.file.encoding=UTF-8
[junit4] FAILURE 58.7s J0 | MultiThreadedOCPTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: We have a failed
SPLITSHARD task
[junit4] > at
__randomizedtesting.SeedInfo.seed([53BB0B78D4E89FC5:D25D8560A3B7FFF9]:0)
[junit4] > at
org.apache.solr.cloud.MultiThreadedOCPTest.testTaskExclusivity(MultiThreadedOCPTest.java:125)
[junit4] > at
org.apache.solr.cloud.MultiThreadedOCPTest.doTest(MultiThreadedOCPTest.java:71)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 3784487 T10355 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J0/./solr.cloud.MultiThreadedOCPTest-53BB0B78D4E89FC5-001
[junit4] 2> 58682 T10354 ccr.ThreadLeakControl.checkThreadLeaks WARNING
Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene49: {}, docValues:{},
sim=DefaultSimilarity, locale=ko, timezone=Antarctica/Casey
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60
(64-bit)/cpus=16,threads=1,free=225480784,total=368574464
[junit4] 2> NOTE: All tests run in this JVM: [TestSurroundQueryParser,
TestRandomMergePolicy, TestStressReorder, TestPartialUpdateDeduplication,
PathHierarchyTokenizerFactoryTest, TestManagedSynonymFilterFactory,
SuggesterWFSTTest, SignatureUpdateProcessorFactoryTest,
DistributedSpellCheckComponentTest, TestRangeQuery, JsonLoaderTest,
TestSolrDeletionPolicy1, OverseerTest, RollingRestartTest,
ExternalFileFieldSortTest, TestBinaryResponseWriter, TestRemoteStreaming,
TriLevelCompositeIdRoutingTest, CurrencyFieldOpenExchangeTest,
XmlUpdateRequestHandlerTest, TestHashPartitioner, SpellPossibilityIteratorTest,
TestDynamicFieldResource, TestComponentsName, TestReRankQParserPlugin,
DateFieldTest, ReplicationFactorTest, TestFieldResource, StressHdfsTest,
TestSimpleQParserPlugin, TestManagedSchema, TestLuceneMatchVersion, TestConfig,
TestFieldTypeCollectionResource, CoreAdminHandlerTest,
DocExpirationUpdateProcessorFactoryTest, CursorPagingTest, SyncSliceTest,
TestCollapseQParserPlugin, TestRequestStatusCollectionAPI,
BasicFunctionalityTest, TestComplexPhraseQParserPlugin,
ParsingFieldUpdateProcessorsTest, TestCloudManagedSchemaConcurrent,
ResourceLoaderTest, PrimUtilsTest, DocValuesMultiTest, TestFaceting,
ZkControllerTest, MinimalSchemaTest, SimpleFacetsTest, UpdateParamsTest,
TestStressUserVersions, BadCopyFieldTest, TestIntervalFaceting,
SolrTestCaseJ4Test, MergeStrategyTest, CollectionsAPIAsyncDistributedZkTest,
RegexBoostProcessorTest, StandardRequestHandlerTest, UnloadDistributedZkTest,
TestStressVersions, TestDFRSimilarityFactory, OverseerCollectionProcessorTest,
TestCollationKeyRangeQueries, TestLMJelinekMercerSimilarityFactory,
TestFastOutputStream, TestNRTOpen, TestFieldTypeResource,
PingRequestHandlerTest, TestSchemaResource, PluginInfoTest,
IndexBasedSpellCheckerTest, TestManagedResource, SpellCheckCollatorTest,
HdfsChaosMonkeySafeLeaderTest, BadIndexSchemaTest, TestSort,
SpellCheckComponentTest, ZkCLITest, QueryEqualityTest, MultiThreadedOCPTest]
[junit4] Completed on J0 in 59.22s, 1 test, 1 failure <<< FAILURES!
[...truncated 695 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:474:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:447:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:496:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299:
The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923:
There were test failures: 411 suites, 1707 tests, 1 error, 1 failure, 50
ignored (8 assumptions)
Total time: 237 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #586
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 460095004 bytes
Compression is 0.0%
Took 1 min 18 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
