Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10956/
Java: 32bit/ibm-j9-jdk7
-Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
2 tests failed.
REGRESSION:
org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.testDistribSearch
Error Message:
Give up waiting for no results: q=id%3A999&rows=0&_trace=did_it_expire_yet
expected:<0> but was:<1>
Stack Trace:
java.lang.AssertionError: Give up waiting for no results:
q=id%3A999&rows=0&_trace=did_it_expire_yet expected:<0> but was:<1>
at
__randomizedtesting.SeedInfo.seed([FF1D7A7A3E09F4D2:7EFBF462495694EE]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at
org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.waitForNoResults(DistribDocExpirationUpdateProcessorTest.java:189)
at
org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.doTest(DistribDocExpirationUpdateProcessorTest.java:95)
at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:871)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:619)
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:853)
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([FF1D7A7A3E09F4D2:FB15F5892CAC1BF3]:0)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:619)
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:853)
Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
... 48 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 49 more
Build Log:
[...truncated 11131 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-FF1D7A7A3E09F4D2-001/init-core-data-001
[junit4] 2> 21793 T77 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 21793 T77 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 21794 T77 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 21799 T77 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 21804 T77 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 21807 T78 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 21906 T77 oasc.ZkTestServer.run start zk server on port:38571
[junit4] 2> 21943 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 21979 T86 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@a691f30f
name:ZooKeeperConnection Watcher:127.0.0.1:38571 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 21980 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 21995 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 21996 T79 oazs.NIOServerCnxn.doIO WARN caught end of stream
exception EndOfStreamException: Unable to read additional data from client
sessionid 0x1480275d35d0000, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 22000 T88 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@ab1b8383
name:ZooKeeperConnection Watcher:127.0.0.1:38571 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 22000 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 22002 T77 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 22013 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 22017 T90 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@66795981
name:ZooKeeperConnection Watcher:127.0.0.1:38571/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 22017 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 22018 T77 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 22024 T77 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 22029 T77 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 22032 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 22045 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 22047 T92 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5dd3fb51
name:ZooKeeperConnection Watcher:127.0.0.1:38571/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 22048 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 22050 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 22054 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 22062 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 22064 T96 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@eae1c738
name:ZooKeeperConnection Watcher:127.0.0.1:38571/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 22065 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 22065 T77 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 22068 T77 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 22072 T77 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 22075 T77 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 22082 T77 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:38571_solr
[junit4] 2> 22083 T77 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 22087 T77 oasc.Overseer.start Overseer
(id=92326497441611780-127.0.0.1:38571_solr-n_0000000000) starting
[junit4] 2> 22095 T77 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 22102 T77 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 22108 T77 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 22113 T77 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 22119 T77 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 22137 T77 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 22148 T77 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 22151 T98 oasc.OverseerCollectionProcessor.run Process current
queue of collection creations
[junit4] 2> 22156 T97 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 23156 T100 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 23166 T97 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> 23167 T97 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection1 with shards [shard1]
[junit4] 2> 23174 T97 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 23192 T94 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> 23192 T93 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> 23658 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 23679 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 23690 T100 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 23706 T100 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 23706 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 23709 T97 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> 23710 T97 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 23819 T93 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> 23821 T94 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> 24161 T98 oasc.OverseerCollectionProcessor.amILeader
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:514)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:272)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 24161 T98 oasc.OverseerCollectionProcessor.amILeader According
to ZK I (id=92326497441611780-127.0.0.1:38571_solr-n_0000000000) am no longer a
leader.
[junit4] 2> 24885 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 24907 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 24910 T102 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@4e83fc5d
name:ZooKeeperConnection Watcher:127.0.0.1:38571/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 24911 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 24912 T77 oasc.Overseer.close Overseer
(id=92326497441611780-127.0.0.1:38571_solr-n_0000000000) closing
[junit4] 2> 24914 T97 oasc.Overseer$ClusterStateUpdater.run Overseer Loop
exiting : 127.0.0.1:38571_solr
[junit4] 2> 24914 T77 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 24916 T103
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 24918 T77 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 24925 T77 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:38571_solr
[junit4] 2> 24926 T77 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 24931 T77 oasc.Overseer.start Overseer
(id=92326497441611781-127.0.0.1:38571_solr-n_0000000001) starting
[junit4] 2> 24955 T77 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 24956 T105 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 24959 T104 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 24967 T104 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> 24968 T104 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 24975 T107 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 24977 T93 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> 24977 T94 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> 25033 T107 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 25034 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 25047 T77 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92326497441611779-node1_core1-n_0000000002
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:619)
[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:853)
[junit4] 2>
[junit4] 2> 25051 T93 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 25053 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 25054 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 25053 T104 oasc.SolrException.log ERROR Problem cleaning up
collection in
zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException:
KeeperErrorCode = Directory not empty for
/collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:189)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:186)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:670)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1104)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:362)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:244)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 25062 T107 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 25065 T104 oasc.Overseer$ClusterStateUpdater.setShardLeader
ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 25170 T94 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> 25171 T93 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> 26061 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 26062 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 27075 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 27078 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 28081 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 28084 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 29087 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 29089 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 30095 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 30096 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 31100 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 31101 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 32106 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 32106 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 33119 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 33120 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 34129 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 34130 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 35139 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 35139 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 36148 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 36149 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 37158 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 37158 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 38167 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 38168 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 39178 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 39179 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 40187 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 40188 T108 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 40197 T108 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.solr.common.SolrException: Could not register as the leader because
creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2> Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] 2> ... 10 more
[junit4] 2> Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
[junit4] 2> at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] 2> at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 40203 T77 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:38571 38571
[junit4] 2> 40911 T78 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:38571 38571
[junit4] 2> 40913 T77 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 40914 T77 oasc.Overseer.close Overseer
(id=92326497441611781-127.0.0.1:38571_solr-n_0000000001) closing
[junit4] 2> 40915 T104 oasc.Overseer$ClusterStateUpdater.run Overseer Loop
exiting : 127.0.0.1:38571_solr
[junit4] 2> 40917 T109
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=FF1D7A7A3E09F4D2
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=pa_IN
-Dtests.timezone=Brazil/East -Dtests.file.encoding=UTF-8
[junit4] ERROR 19.2s 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([FF1D7A7A3E09F4D2:FB15F5892CAC1BF3]:0)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] > at
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] > at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] > at java.lang.Thread.run(Thread.java:853)
[junit4] > Caused by: org.apache.solr.common.SolrException:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] > ... 48 more
[junit4] > Caused by:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode =
NodeExists for /collections/collection1/leaders/shard1
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462)
[junit4] > at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403)
[junit4] > at
org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] > at
org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 49 more
[junit4] 2> 40984 T77 oas.SolrTestCaseJ4.setUp ###Starting
testShardLeaderChange
[junit4] 2> 40984 T77 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 40986 T110 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 41085 T77 oasc.ZkTestServer.run start zk server on port:57827
[junit4] 2> 41087 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 41091 T116 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@91bbb17e
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41092 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41094 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 41098 T118 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@6ee86e5a
name:ZooKeeperConnection Watcher:127.0.0.1:57827 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41098 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41101 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 41103 T120 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@59f2d330
name:ZooKeeperConnection Watcher:127.0.0.1:57827 got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41103 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41104 T77 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 41107 T77 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 41111 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 41111 T121 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 41113 T124 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@49f5179f
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41114 T121 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41114 T125 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@a665673e
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41115 T121 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 41115 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41116 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 41117 T77 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 41119 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 41120 T77 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 41122 T121 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 41124 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 41125 T121 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:57827_solr
[junit4] 2> 41125 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 41128 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 41128 T121 oasc.Overseer.start Overseer
(id=92326498696364035-127.0.0.1:57827_solr-n_0000000000) starting
[junit4] 2> 41131 T121 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 41133 T77 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 41136 T121 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 41140 T121 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 41144 T121 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 41149 T121 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 41154 T121 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 41161 T121 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 41162 T128 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 41162 T121 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 41165 T121 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 41167 T131 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@de4d5e38
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41167 T121 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41168 T121 oasc.Overseer.close Overseer
(id=92326498696364035-127.0.0.1:57827_solr-n_0000000000) closing
[junit4] 2> 41168 T128 oasc.OverseerCollectionProcessor.run ERROR Unable
to prioritize overseer
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /roles.json
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:256)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:253)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:253)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:259)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 41168 T121 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 41171 T121 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 41174 T121 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:57827_solr
[junit4] 2> 41174 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 41177 T121 oasc.Overseer.start Overseer
(id=92326498696364037-127.0.0.1:57827_solr-n_0000000001) starting
[junit4] 2> 41189 T121 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 41190 T133 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 41191 T132 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 41195 T132 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 41195 T132 oasc.Overseer$ClusterStateUpdater.createCollection
Create collection collection1 with shards [shard1]
[junit4] 2> 41196 T132 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 41200 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 41201 T126 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> 41637 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 41661 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 41674 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 41678 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 41693 T132 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 41694 T132 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 41698 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 41699 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 41700 T137 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@338d9373
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 41701 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 41702 T126 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> 41703 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 41707 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 41712 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 41712 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 41717 T132 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 41718 T132 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 41725 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 41727 T132 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 41728 T132 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=1
[junit4] 2> 41728 T132 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 41837 T126 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 41837 T138 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 42226 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 42247 T139 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 42250 T138 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 42260 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 42371 T138 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> 43747 T126 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 43754 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 43757 T141 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@33cc764d
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 43758 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 43761 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 43768 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 43778 T135 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 43778 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 43784 T132 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 43785 T132 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 43793 T121 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 43795 T143 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 43796 T121 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 43798 T145 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@a3743855
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 43798 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 43798 T121 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 43800 T121 oasc.Overseer.close Overseer
(id=92326498696364037-127.0.0.1:57827_solr-n_0000000001) closing
[junit4] 2> 43800 T132 oasc.Overseer$ClusterStateUpdater.run Overseer Loop
exiting : 127.0.0.1:57827_solr
[junit4] 2> 43800 T121 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 43801 T146
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 43802 T121 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 43805 T121 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:57827_solr
[junit4] 2> 43806 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 43808 T121 oasc.Overseer.start Overseer
(id=92326498696364040-127.0.0.1:57827_solr-n_0000000002) starting
[junit4] 2> 43808 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 43810 T148 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@819bb5d1
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 43810 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 43812 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 43815 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 43819 T121 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 43820 T151 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 43820 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 43823 T149 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 43824 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 43825 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 43827 T150 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 43827 T143 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 43829 T149 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 43833 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 43833 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 43836 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 43841 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 43842 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 43844 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 43846 T143 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 43846 T150 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 44036 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 44036 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 44041 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 44042 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 44050 T142 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 44052 T154 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 44057 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 44164 T154 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> 45550 T143 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 45557 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 45560 T156 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@199aadbf
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 45561 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 45565 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 45572 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 45582 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 45582 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 45588 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 45589 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45609 T158 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 45610 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 45610 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 45612 T149 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 45613 T149 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45620 T77 oascc.ConnectionManager.waitForConnected Waiting for
client to connect to ZooKeeper
[junit4] 2> 45621 T153 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 45622 T160 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@78f5d24e
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 45623 T77 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 45623 T121 oasc.OverseerTest$OverseerRestarter.run Killing
overseer.
[junit4] 2> 45624 T158 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> 45625 T77
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 45626 T121 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 45629 T162 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@8b397e9b
name:ZooKeeperConnection Watcher:127.0.0.1:57827/solr got event WatchedEvent
state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 45629 T121 oascc.ConnectionManager.waitForConnected Client is
connected to ZooKeeper
[junit4] 2> 45630 T121 oasc.Overseer.close Overseer
(id=92326498696364040-127.0.0.1:57827_solr-n_0000000002) closing
[junit4] 2> 45630 T121 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 45630 T149 oasc.Overseer$ClusterStateUpdater.run Overseer Loop
exiting : 127.0.0.1:57827_solr
[junit4] 2> 45630 T77 oascc.SolrZkClient.makePath makePath:
/live_nodes/node2
[junit4] 2> 45631 T163
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 45632 T121 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 45637 T121 oasc.OverseerElectionContext.runLeaderProcess I am
going to be the leader 127.0.0.1:57827_solr
[junit4] 2> 45637 T121 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 45639 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 45641 T121 oasc.Overseer.start Overseer
(id=92326498696364044-127.0.0.1:57827_solr-n_0000000003) starting
[junit4] 2> 45650 T77 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 45652 T121 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 45652 T166 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 45656 T165 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 45657 T165 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 45658 T165 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45659 T164 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> 45660 T168 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 45663 T165 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 45663 T165 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45664 T164 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> 45668 T164 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> 45670 T165 oasc.Overseer$ClusterStateUpdater.run Starting to
work on the main queue
[junit4] 2> 45673 T165 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 45674 T165 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45677 T169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 45678 T165 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 45678 T165 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 45684 T169 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 45686 T164 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> 47158 T158 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:273)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 47158 T157 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2
[...truncated too long message...]
0;path=./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001/tempDir-001/jetty4/index.20140823145719403;done=false>>]
[junit4] 2> 1128484 T2817 oasc.CachingDirectoryFactory.close Closing
directory:
./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001/tempDir-001/jetty4/index.20140823145719403
[junit4] 2> 1128484 T2817 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001/tempDir-001/jetty4
[CachedDir<<refCount=0;path=./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001/tempDir-001/jetty4;done=false>>]
[junit4] 2> 1128485 T2817 oasc.CachingDirectoryFactory.close Closing
directory:
./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001/tempDir-001/jetty4
[junit4] 2> 1128485 T2817
oasup.DocExpirationUpdateProcessorFactory$2.postClose Triggering hard shutdown
of DocExpiration Executor
[junit4] 2> 1128486 T2939 C1243 P47391 oasup.LogUpdateProcessor.finish
[collection1] {} 0 2452
[junit4] 2> 1128486 T2939 C1243 P47391
oasup.DocExpirationUpdateProcessorFactory$DeleteExpiredDocsRunnable.run ERROR
Runtime error in periodic deletion of expired docs: Exception finding leader
for shard shard2 org.apache.solr.common.SolrException: Exception finding leader
for shard shard2
[junit4] 2> at
org.apache.solr.update.processor.DistributedUpdateProcessor.doDeleteByQuery(DistributedUpdateProcessor.java:1301)
[junit4] 2> at
org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:1167)
[junit4] 2> at
org.apache.solr.update.processor.LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:121)
[junit4] 2> at
org.apache.solr.update.processor.UpdateRequestProcessor.processDelete(UpdateRequestProcessor.java:55)
[junit4] 2> at
org.apache.solr.update.processor.DocExpirationUpdateProcessorFactory$DeleteExpiredDocsRunnable.run(DocExpirationUpdateProcessorFactory.java:407)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:482)
[junit4] 2> at
java.util.concurrent.FutureTask.runAndReset(FutureTask.java:315)
[junit4] 2> at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:193)
[junit4] 2> at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:308)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1176)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2> Caused by: java.lang.InterruptedException
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at java.lang.Thread.sleep(Thread.java:977)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:566)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:551)
[junit4] 2> at
org.apache.solr.update.processor.DistributedUpdateProcessor.doDeleteByQuery(DistributedUpdateProcessor.java:1299)
[junit4] 2> ... 11 more
[junit4] 2>
[junit4] 2> 1128487 T2817 oasc.Overseer.close Overseer
(id=92326554662076429-127.0.0.1:47391_t_mv-n_0000000004) closing
[junit4] 2> 1128488 T3049 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:47391_t_mv
[junit4] 2> 1129988 T3052
oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read
the data org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:307)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:320)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:292)
[junit4] 2>
[junit4] 2> 1129988 T3041 oascc.ZkStateReader$3.process WARN ZooKeeper
watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1130010 T2817 oejsh.ContextHandler.doStop stopped
o.e.j.s.ServletContextHandler{/t_mv,null}
[junit4] 2> 1135001 T2817 oas.SolrTestCaseJ4.tearDown ###Ending
testDistribSearch
[junit4] 2> 1135002 T2817 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:37363 37363
[junit4] 2> 1135687 T2818 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:37363 37363
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=DistribDocExpirationUpdateProcessorTest
-Dtests.method=testDistribSearch -Dtests.seed=FF1D7A7A3E09F4D2
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_BH
-Dtests.timezone=Europe/Simferopol -Dtests.file.encoding=UTF-8
[junit4] FAILURE 241s J1 |
DistribDocExpirationUpdateProcessorTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Give up waiting for no
results: q=id%3A999&rows=0&_trace=did_it_expire_yet expected:<0> but was:<1>
[junit4] > at
__randomizedtesting.SeedInfo.seed([FF1D7A7A3E09F4D2:7EFBF462495694EE]:0)
[junit4] > at
org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.waitForNoResults(DistribDocExpirationUpdateProcessorTest.java:189)
[junit4] > at
org.apache.solr.cloud.DistribDocExpirationUpdateProcessorTest.doTest(DistribDocExpirationUpdateProcessorTest.java:95)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:871)
[junit4] > at java.lang.Thread.run(Thread.java:853)
[junit4] 2> 1135700 T2817 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.DistribDocExpirationUpdateProcessorTest-FF1D7A7A3E09F4D2-001
[junit4] 2> NOTE: test params are: codec=Lucene49,
sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=ar_BH,
timezone=Europe/Simferopol
[junit4] 2> NOTE: Linux 3.13.0-34-generic x86/IBM Corporation 1.7.0
(32-bit)/cpus=8,threads=1,free=125404200,total=230359040
[junit4] 2> NOTE: All tests run in this JVM: [UUIDFieldTest,
TestManagedResource, TestDistribDocBasedVersion, SolrInfoMBeanTest,
TestDefaultSearchFieldResource, TestRequestStatusCollectionAPI, CopyFieldTest,
TestNRTOpen, TestZkChroot, DirectUpdateHandlerOptimizeTest, NumericFieldsTest,
SynonymTokenizerTest, DistributedQueryComponentCustomSortTest,
ConvertedLegacyTest, HdfsCollectionsAPIDistributedZkTest, QueryParsingTest,
TestRestManager, AsyncMigrateRouteKeyTest, TestIndexingPerformance,
TestHighFrequencyDictionaryFactory, TestReloadAndDeleteDocs, OutputWriterTest,
TestSearcherReuse, CollectionsAPIDistributedZkTest, SystemInfoHandlerTest,
DocValuesTest, AddBlockUpdateTest, TestSystemIdResolver, TestFieldSortValues,
TestShortCircuitedRequests, TestSolrXml, TestCollationField, AssignTest,
TestRealTimeGet, SearchHandlerTest, DistributedExpandComponentTest,
ChaosMonkeySafeLeaderTest, HdfsChaosMonkeySafeLeaderTest, SolrPluginUtilsTest,
UniqFieldsUpdateProcessorFactoryTest, DistributedFacetPivotLargeTest,
TestLFUCache, LeaderElectionIntegrationTest, BlockCacheTest,
TestFieldTypeCollectionResource, DefaultValueUpdateProcessorTest,
TestFileDictionaryLookup, TestMiniSolrCloudCluster, TestRecovery,
SimplePostToolTest, DistributedDebugComponentTest, TestUpdate,
TestAtomicUpdateErrorCases, BinaryUpdateRequestHandlerTest,
TestReversedWildcardFilterFactory, SolrXmlInZkTest, TestFieldResource,
ScriptEngineTest, TestPhraseSuggestions,
DistribDocExpirationUpdateProcessorTest]
[junit4] Completed on J1 in 241.26s, 1 test, 1 failure <<< FAILURES!
[...truncated 888 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:485: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:478: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:48: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:494: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1343:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:958:
There were test failures: 419 suites, 1733 tests, 1 error, 1 failure, 47
ignored (18 assumptions)
Total time: 108 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/ibm-j9-jdk7
-Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
