Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11037/
Java: 32bit/jdk1.7.0_65 -server -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.TestDistributedSearch.testDistribSearch
Error Message:
.facet_counts.facet_fields.a_n_tdt.1970-01-01T00:00:00Z!=2010-04-20T11:00:00Z
(unordered or missing)
Stack Trace:
junit.framework.AssertionFailedError:
.facet_counts.facet_fields.a_n_tdt.1970-01-01T00:00:00Z!=2010-04-20T11:00:00Z
(unordered or missing)
at
__randomizedtesting.SeedInfo.seed([5547E29057A024AB:D4A16C8820FF4497]:0)
at junit.framework.Assert.fail(Assert.java:50)
at
org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:842)
at
org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:861)
at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:562)
at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
at
org.apache.solr.TestDistributedSearch.doTest(TestDistributedSearch.java:180)
at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:875)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election
Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
for /collections/collection1/leader_elect/shard1/election
at
__randomizedtesting.SeedInfo.seed([5547E29057A024AB:514F6D634505CB8A]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11366 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-5547E29057A024AB-001/init-core-data-001
[junit4] 2> 1604704 T4268 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl
(false) and clientAuth (false)
[junit4] 2> 1604704 T4268 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1604704 T4268 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1604707 T4268 oas.SolrTestCaseJ4.setUp ###Starting
testPlaceholders
[junit4] 2> 1604708 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1604708 T4269 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1604816 T4268 oasc.ZkTestServer.run start zk server on
port:46180
[junit4] 2> 1604817 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1604820 T4275 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@cacff9 name:ZooKeeperConnection
Watcher:127.0.0.1:46180/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1604820 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1604821 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1604822 T4277 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1a5eef5 name:ZooKeeperConnection
Watcher:127.0.0.1:46180 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1604822 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1604824 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1604825 T4279 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@9022ad name:ZooKeeperConnection
Watcher:127.0.0.1:46180 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1604825 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1604825 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1604828 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1604830 T4268 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1604831 T4268 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1604832 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1604839 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1604840 T4281 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@ada0d1 name:ZooKeeperConnection
Watcher:127.0.0.1:46180/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1604840 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1604841 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1604842 T4268 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1604851 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1604852 T4285 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@e7e1e7 name:ZooKeeperConnection
Watcher:127.0.0.1:46180/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1604852 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1604853 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1604854 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1604855 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1604857 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1604858 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:46180_solr
[junit4] 2> 1604858 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1604860 T4268 oasc.Overseer.start Overseer
(id=92288351107088388-127.0.0.1:46180_solr-n_0000000000) starting
[junit4] 2> 1604861 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1604862 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1604864 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1604866 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1604868 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1604870 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1604873 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1604873 T4287 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1604874 T4286 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1604876 T4286 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1604876 T4286
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6,
shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 1604877 T4286 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1604878 T4289 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1604879 T4282 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> 1604879 T4283 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> 1605376 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1605381 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1605385 T4289 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1605389 T4268 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46180 46180
[junit4] 2> 1605947 T4269 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:46180 46180
[junit4] 2> 1605949 T4268 oas.SolrTestCaseJ4.tearDown ###Ending
testPlaceholders
[junit4] 2> 1605949 T4268 oasc.Overseer.close Overseer
(id=92288351107088388-127.0.0.1:46180_solr-n_0000000000) closing
[junit4] 2> 1605950 T4286 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:46180_solr
[junit4] 2> 1605951 T4290
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1605955 T4268 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignment
[junit4] 2> 1605955 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1605956 T4291 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1606056 T4268 oasc.ZkTestServer.run start zk server on
port:51454
[junit4] 2> 1606057 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1606059 T4297 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@5c931c name:ZooKeeperConnection
Watcher:127.0.0.1:51454 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1606059 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1606061 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1606062 T4299 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@cca746 name:ZooKeeperConnection
Watcher:127.0.0.1:51454 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1606062 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1606063 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1606065 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1606066 T4301 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@315e42 name:ZooKeeperConnection
Watcher:127.0.0.1:51454/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1606066 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1606067 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1606068 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1606069 T4303 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@775b26 name:ZooKeeperConnection
Watcher:127.0.0.1:51454/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1606069 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1606069 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1606070 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1606072 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1606073 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1606074 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:51454_solr
[junit4] 2> 1606075 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1606076 T4268 oasc.Overseer.start Overseer
(id=92288351188877315-127.0.0.1:51454_solr-n_0000000000) starting
[junit4] 2> 1606077 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1606079 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1606080 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1606082 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1606084 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1606086 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1606089 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1606089 T4305 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1606090 T4268 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1606090 T4304 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1606092 T4268 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1606093 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1606094 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1606096 T4308 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1e910c3 name:ZooKeeperConnection
Watcher:127.0.0.1:51454/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1606096 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1606097 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1606099 T4268 oascc.SolrZkClient.makePath makePath:
/live_nodes/127.0.0.1
[junit4] 2> 1606104 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1606106 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1606106 T4304
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1606107 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1606109 T4309 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> 1606109 T4310 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> 1606603 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1606608 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1606611 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1606614 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1606614 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1606614 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1606615 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1606616 T4309 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> 1606616 T4310 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> 1607112 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1607117 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard3
[junit4] 2> 1607121 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1607124 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1607124 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1607125 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1607126 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1607127 T4309 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> 1607127 T4310 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> 1607622 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1607627 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard2
[junit4] 2> 1607630 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1607633 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1607633 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1607633 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1607635 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1607636 T4310 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> 1607636 T4309 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> 1608131 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1608137 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1608138 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1608138 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1608138 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard3
[junit4] 2> 1608241 T4310 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> 1608241 T4309 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> 1608637 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard3/election
[junit4] 2> 1608642 T4311 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1608644 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1608644 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Collection already exists with numShards=3
[junit4] 2> 1608644 T4304 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard2
[junit4] 2> 1608746 T4310 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> 1608746 T4309 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> 1609142 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard2/election
[junit4] 2> 1609148 T4292 oazs.NIOServerCnxn.doIO WARN caught end of
stream exception EndOfStreamException: Unable to read additional data from
client sessionid 0x147dfc435850004, 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:745)
[junit4] 2>
[junit4] 2> 1609148 T4312 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1609148 T4308 oaz.ClientCnxn$EventThread.processEvent ERROR
Error while calling watcher java.util.concurrent.RejectedExecutionException:
Task java.util.concurrent.FutureTask@1a713ca rejected from
java.util.concurrent.ThreadPoolExecutor@466e9[Shutting down, pool size = 2,
active threads = 2, queued tasks = 0, completed tasks = 8]
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
[junit4] 2> at
java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:206)
[junit4] 2> at
org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at
org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1610648 T4310 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /collections/collection1/leader_elect/shard2/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:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1610650 T4268 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:51454 51454
[junit4] 2> 1611085 T4291 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:51454 51454
[junit4] 2> 1611086 T4268 oas.SolrTestCaseJ4.tearDown ###Ending
testShardAssignment
[junit4] 2> 1611087 T4268 oasc.Overseer.close Overseer
(id=92288351188877315-127.0.0.1:51454_solr-n_0000000000) closing
[junit4] 2> 1611087 T4304 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:51454_solr
[junit4] 2> 1611088 T4313
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1611093 T4268 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1611093 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1611094 T4314 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1611194 T4268 oasc.ZkTestServer.run start zk server on
port:50873
[junit4] 2> 1611200 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611201 T4320 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1f4feab name:ZooKeeperConnection
Watcher:127.0.0.1:50873/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1611202 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611206 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611207 T4322 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@c8ac4b name:ZooKeeperConnection
Watcher:127.0.0.1:50873 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1611207 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611209 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611210 T4324 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@16d2b7d name:ZooKeeperConnection
Watcher:127.0.0.1:50873 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1611211 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611211 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1611213 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1611215 T4268 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1611216 T4268 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1611218 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1611220 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1611223 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611223 T4326 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1ebe264 name:ZooKeeperConnection
Watcher:127.0.0.1:50873/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1611224 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611225 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1611225 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1611227 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1611228 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1611230 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:50873_solr
[junit4] 2> 1611230 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1611231 T4268 oasc.Overseer.start Overseer
(id=92288351525666819-127.0.0.1:50873_solr-n_0000000000) starting
[junit4] 2> 1611233 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1611236 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1611238 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1611240 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1611243 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1611247 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1611248 T4328 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1611252 T4327 oasc.Overseer$ClusterStateUpdater.run Replaying
operations from work queue.
[junit4] 2> 1611252 T4327 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1611253 T4330 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1611255 T4327 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1611256 T4330 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1611258 T4327 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1611260 T4327 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1611262 T4331 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1611263 T4330 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1611368 T4268 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:50873 50873
[junit4] 2> 1611818 T4314 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:50873 50873
[junit4] 2> 1611820 T4268 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1611820 T4268 oasc.Overseer.close Overseer
(id=92288351525666819-127.0.0.1:50873_solr-n_0000000000) closing
[junit4] 2> 1611821 T4327 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:50873_solr
[junit4] 2> 1611823 T4332
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1611829 T4268 oas.SolrTestCaseJ4.setUp ###Starting
testOverseerFailure
[junit4] 2> 1611829 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1611830 T4333 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1611930 T4268 oasc.ZkTestServer.run start zk server on
port:40099
[junit4] 2> 1611931 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611933 T4339 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@ff693a name:ZooKeeperConnection
Watcher:127.0.0.1:40099 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1611933 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611935 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611936 T4341 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@12fac1c name:ZooKeeperConnection
Watcher:127.0.0.1:40099 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1611936 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611936 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1611939 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611940 T4343 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1df2969 name:ZooKeeperConnection
Watcher:127.0.0.1:40099/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1611940 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611941 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1611942 T4268 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1611943 T4268 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1611944 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1611946 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611947 T4345 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@12eded name:ZooKeeperConnection
Watcher:127.0.0.1:40099/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1611947 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611948 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1611950 T4268 oascc.SolrZkClient.makePath makePath:
/live_nodes/node1
[junit4] 2> 1611953 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1611953 T4349 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@183bb88 name:ZooKeeperConnection
Watcher:127.0.0.1:40099/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1611954 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1611954 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1611955 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1611956 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1611957 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1611959 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:40099_solr
[junit4] 2> 1611959 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1611960 T4268 oasc.Overseer.start Overseer
(id=92288351573835780-127.0.0.1:40099_solr-n_0000000000) starting
[junit4] 2> 1611961 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1611963 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1611965 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1611967 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1611969 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1611972 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1611976 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1611976 T4351 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1611977 T4350 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1612988 T4353 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1612991 T4350 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> 1612991 T4350
oasc.Overseer$ClusterStateUpdater.createCollection Create collection
collection1 with shards [shard1]
[junit4] 2> 1612991 T4350 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1612993 T4347 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> 1612993 T4346 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> 1613488 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1613496 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leaders/shard1
[junit4] 2> 1613501 T4353 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1613504 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1613505 T4350 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> 1613505 T4350 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1613507 T4353 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1613508 T4347 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> 1613508 T4346 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> 1613513 T4334 oazs.NIOServerCnxn.doIO WARN caught end of
stream exception EndOfStreamException: Unable to read additional data from
client sessionid 0x147dfc44c770004, 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:745)
[junit4] 2>
[junit4] 2> 1613985 T4351 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:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:516)
[junit4] 2> at
org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:271)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1613985 T4351 oasc.OverseerCollectionProcessor.amILeader
According to ZK I (id=92288351573835780-127.0.0.1:40099_solr-n_0000000000) am
no longer a leader.
[junit4] 2> 1614515 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1614519 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1614520 T4355 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1dc1ae1 name:ZooKeeperConnection
Watcher:127.0.0.1:40099/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1614520 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1614521 T4268 oasc.Overseer.close Overseer
(id=92288351573835780-127.0.0.1:40099_solr-n_0000000000) closing
[junit4] 2> 1614521 T4350 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:40099_solr
[junit4] 2> 1614522 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1614523 T4356
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1614524 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1614525 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:40099_solr
[junit4] 2> 1614525 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1614527 T4268 oasc.Overseer.start Overseer
(id=92288351573835781-127.0.0.1:40099_solr-n_0000000001) starting
[junit4] 2> 1614532 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1614532 T4358 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1614534 T4357 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1614535 T4357 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> 1614536 T4357 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1614537 T4360 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1614537 T4346 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> 1614537 T4347 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> 1614590 T4268 oascc.SolrZkClient.makePath makePath:
/collections/collection1/leader_elect/shard1/election
[junit4] 2> 1614590 T4360 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1614594 T4268 oasc.LeaderElector.checkIfIamLeader WARN Failed
setting watch org.apache.zookeeper.KeeperException$NoNodeException:
KeeperErrorCode = NoNode for
/collections/collection1/leader_elect/shard1/election/92288351573835779-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:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] 2> at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1614595 T4346 oasc.LeaderElector.checkIfIamLeader WARN Our
node is no longer in line to be leader
[junit4] 2> 1614596 T4361 oasc.LeaderElector$ElectionWatcher.process WARN
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
for /collections/collection1/leader_elect/shard1/election
[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.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:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:262)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1614599 T4268 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40099 40099
[junit4] 2> 1615294 T4333 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:40099 40099
[junit4] 2> 1615295 T4268 oas.SolrTestCaseJ4.tearDown ###Ending
testOverseerFailure
[junit4] 2> 1615295 T4268 oasc.Overseer.close Overseer
(id=92288351573835781-127.0.0.1:40099_solr-n_0000000001) closing
[junit4] 2> 1615297 T4357 oasc.SolrException.log ERROR Cleaning up
collection in zk was interrupted:collection1:java.lang.InterruptedException:
sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
[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.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1098)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:363)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:246)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1615297 T4357 oasc.Overseer$ClusterStateUpdater.run WARN Solr
cannot talk to ZK, exiting Overseer main queue loop
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode =
Session expired for /overseer/queue-work/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:273)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:270)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:270)
[junit4] 2> at
org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:369)
[junit4] 2> at
org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:353)
[junit4] 2> at
org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:259)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1615298 T4357 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:40099_solr
[junit4] 2> 1615299 T4362
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest
-Dtests.method=testOverseerFailure -Dtests.seed=5547E29057A024AB
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_UY
-Dtests.timezone=America/Santa_Isabel -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 3.48s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode
for /collections/collection1/leader_elect/shard1/election
[junit4] > at
__randomizedtesting.SeedInfo.seed([5547E29057A024AB:514F6D634505CB8A]:0)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] > at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at
org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:290)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:287)
[junit4] > at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at
org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:287)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] > at
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at
org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at
org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] > at
org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1615312 T4268 oas.SolrTestCaseJ4.setUp ###Starting
testStateChange
[junit4] 2> 1615313 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1615314 T4363 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1615414 T4268 oasc.ZkTestServer.run start zk server on
port:57017
[junit4] 2> 1615415 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1615417 T4369 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@14ae008 name:ZooKeeperConnection
Watcher:127.0.0.1:57017/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1615417 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1615420 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1615421 T4371 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@172325d name:ZooKeeperConnection
Watcher:127.0.0.1:57017 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1615421 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1615423 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1615424 T4373 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1218652 name:ZooKeeperConnection
Watcher:127.0.0.1:57017 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1615424 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1615425 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1615427 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1615429 T4268 oascc.SolrZkClient.makePath makePath:
/clusterstate.json
[junit4] 2> 1615431 T4268 oascc.SolrZkClient.makePath makePath:
/aliases.json
[junit4] 2> 1615433 T4268
oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state
from ZooKeeper...
[junit4] 2> 1615435 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1615436 T4375 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@13f476c name:ZooKeeperConnection
Watcher:127.0.0.1:57017/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1615436 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1615436 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1615437 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1615439 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1615441 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1615443 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:57017_solr
[junit4] 2> 1615443 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1615445 T4268 oasc.Overseer.start Overseer
(id=92288351802163203-127.0.0.1:57017_solr-n_0000000000) starting
[junit4] 2> 1615448 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1615451 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1615452 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1615454 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-running
[junit4] 2> 1615456 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-completed
[junit4] 2> 1615458 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-queue-work
[junit4] 2> 1615460 T4268 oasc.OverseerAutoReplicaFailoverThread.<init>
Starting OverseerAutoReplicaFailoverThread
autoReplicaFailoverWorkLoopDelay=10000
autoReplicaFailoverWaitAfterExpiration=30000
autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 1615461 T4377 oasc.OverseerCollectionProcessor.run Process
current queue of collection creations
[junit4] 2> 1615462 T4376 oasc.Overseer$ClusterStateUpdater.run Starting
to work on the main queue
[junit4] 2> 1615464 T4376 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1615464 T4376 oasc.Overseer$ClusterStateUpdater.updateState
Assigning new node to shard shard=shard1
[junit4] 2> 1615466 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1615466 T4380 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1615515 T4379 oasc.DistributedQueue$LatchChildWatcher.process
LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type
NodeChildrenChanged
[junit4] 2> 1615516 T4376 oasc.Overseer$ClusterStateUpdater.updateState
Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr";,
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 1615517 T4376 oasc.Overseer$ClusterStateUpdater.updateState
node=core_node1 is already registered
[junit4] 2> 1615517 T4376 oasc.Overseer$ClusterStateUpdater.updateState
shard=shard1 is already registered
[junit4] 2> 1615619 T4380 oascc.ZkStateReader$2.process A cluster state
change: WatchedEvent state:SyncConnected type:NodeDataChanged
path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1615667 T4268 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:57017 57017
[junit4] 2> 1616218 T4363 oasc.ZkTestServer.send4LetterWord connecting to
127.0.0.1:57017 57017
[junit4] 2> 1616219 T4268 oas.SolrTestCaseJ4.tearDown ###Ending
testStateChange
[junit4] 2> 1616219 T4268 oasc.Overseer.close Overseer
(id=92288351802163203-127.0.0.1:57017_solr-n_0000000000) closing
[junit4] 2> 1616220 T4376 oasc.Overseer$ClusterStateUpdater.run Overseer
Loop exiting : 127.0.0.1:57017_solr
[junit4] 2> 1616225 T4381
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:73)
[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:321)
[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:293)
[junit4] 2>
[junit4] 2> 1616229 T4268 oas.SolrTestCaseJ4.setUp ###Starting
testShardAssignmentBigger
[junit4] 2> 1616230 T4268 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1616231 T4382 oasc.ZkTestServer$ZKServerMain.runFromConfig
Starting server
[junit4] 2> 1616331 T4268 oasc.ZkTestServer.run start zk server on
port:56278
[junit4] 2> 1616332 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1616333 T4388 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@3284a1 name:ZooKeeperConnection
Watcher:127.0.0.1:56278 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1616334 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1616336 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1616337 T4390 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@1533f20 name:ZooKeeperConnection
Watcher:127.0.0.1:56278 got event WatchedEvent state:SyncConnected type:None
path:null path:null type:None
[junit4] 2> 1616337 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1616337 T4268 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1616340 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1616341 T4392 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@68d232 name:ZooKeeperConnection
Watcher:127.0.0.1:56278/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1616341 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1616341 T4268 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1616343 T4268 oascc.ConnectionManager.waitForConnected Waiting
for client to connect to ZooKeeper
[junit4] 2> 1616344 T4394 oascc.ConnectionManager.process Watcher
org.apache.solr.common.cloud.ConnectionManager@a1e22d name:ZooKeeperConnection
Watcher:127.0.0.1:56278/solr got event WatchedEvent state:SyncConnected
type:None path:null path:null type:None
[junit4] 2> 1616344 T4268 oascc.ConnectionManager.waitForConnected Client
is connected to ZooKeeper
[junit4] 2> 1616344 T4268 oasu.UpdateShardHandler.<init> Creating
UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 1616345 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect
[junit4] 2> 1616346 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/election
[junit4] 2> 1616348 T4268 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 1616349 T4268 oasc.OverseerElectionContext.runLeaderProcess I
am going to be the leader 127.0.0.1:56278_solr
[junit4] 2> 1616349 T4268 oascc.SolrZkClient.makePath makePath:
/overseer_elect/leader
[junit4] 2> 1616350 T4268 oasc.Overseer.start Overseer
(id=92288351862259715-127.0.0.1:56278_solr-n_0000000000) starting
[junit4] 2> 1616351 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue
[junit4] 2> 1616353 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/queue-work
[junit4] 2> 1616355 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-failure
[junit4] 2> 1616356 T4268 oascc.SolrZkClient.makePath makePath:
/overseer/collection-map-
[...truncated too long message...]
,cumulative_errors=0,transaction_logs_total_size=17895,transaction_logs_total_number=2}
[junit4] 2> 1876365 T4734 oasu.SolrCoreState.decrefSolrCoreState Closing
SolrCoreState
[junit4] 2> 1876365 T4734 oasu.DefaultSolrCoreState.closeIndexWriter
SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1876365 T4734 oasu.DefaultSolrCoreState.closeIndexWriter
closing IndexWriter with IndexWriterCloser
[junit4] 2> 1876367 T4734 oasc.SolrCore.closeSearcher [collection1]
Closing main searcher on request.
[junit4] 2> 1876367 T4734 oasc.CachingDirectoryFactory.close Closing
MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1876367 T4734 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data
[CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data;done=false>>]
[junit4] 2> 1876368 T4734 oasc.CachingDirectoryFactory.close Closing
directory:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data
[junit4] 2> 1876368 T4734 oasc.CachingDirectoryFactory.closeCacheValue
looking to close
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data/index
[CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data/index;done=false>>]
[junit4] 2> 1876368 T4734 oasc.CachingDirectoryFactory.close Closing
directory:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001/tempDir-001/shard0/data/index
[junit4] 2> 1876369 T4734 oejsh.ContextHandler.doStop stopped
o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 1881341 T4734 oas.SolrTestCaseJ4.tearDown ###Ending
testDistribSearch
[junit4] 2> NOTE: reproduce with: ant test
-Dtestcase=TestDistributedSearch -Dtests.method=testDistribSearch
-Dtests.seed=5547E29057A024AB -Dtests.multiplier=3 -Dtests.slow=true
-Dtests.locale=de_CH -Dtests.timezone=Asia/Saigon
-Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 14.6s J1 | TestDistributedSearch.testDistribSearch <<<
[junit4] > Throwable #1: junit.framework.AssertionFailedError:
.facet_counts.facet_fields.a_n_tdt.1970-01-01T00:00:00Z!=2010-04-20T11:00:00Z
(unordered or missing)
[junit4] > at
__randomizedtesting.SeedInfo.seed([5547E29057A024AB:D4A16C8820FF4497]:0)
[junit4] > at junit.framework.Assert.fail(Assert.java:50)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:842)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:861)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:562)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
[junit4] > at
org.apache.solr.TestDistributedSearch.doTest(TestDistributedSearch.java:180)
[junit4] > at
org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:875)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1881364 T4734 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./temp/solr.TestDistributedSearch-5547E29057A024AB-001
[junit4] 2> NOTE: test params are: codec=Lucene410:
{b_n_tdt=PostingsFormat(name=Direct), n_tl1=Pulsing41(freqCutoff=16
minBlockSize=9 maxBlockSize=66), a_i1=PostingsFormat(name=Direct),
range_facet_l=PostingsFormat(name=Direct), multiDefault=Pulsing41(freqCutoff=16
minBlockSize=9 maxBlockSize=66), a_t=PostingsFormat(name=Direct),
intDefault=PostingsFormat(name=Direct), other_tl1=PostingsFormat(name=Direct),
n_tf1=PostingsFormat(name=Direct), id=PostingsFormat(name=Lucene41WithOrds),
SubjectTerms_mfacet=PostingsFormat(name=Direct),
n_tdt1=PostingsFormat(name=Direct), n_td1=Pulsing41(freqCutoff=16
minBlockSize=9 maxBlockSize=66), n_d1=PostingsFormat(name=Direct),
lowerfilt=Pulsing41(freqCutoff=16 minBlockSize=9 maxBlockSize=66),
n_ti1=PostingsFormat(name=Lucene41WithOrds), text=PostingsFormat(name=Memory
doPackFST= false), timestamp=PostingsFormat(name=Direct),
n_l1=PostingsFormat(name=Direct), foo_d=PostingsFormat(name=Lucene41WithOrds),
a_n_tdt=PostingsFormat(name=Lucene41WithOrds),
lowerfilt1and2=Pulsing41(freqCutoff=16 minBlockSize=9 maxBlockSize=66),
oddField_s=PostingsFormat(name=Memory doPackFST= false),
n_dt1=Pulsing41(freqCutoff=16 minBlockSize=9 maxBlockSize=66),
_version_=PostingsFormat(name=Direct),
rnd_b=PostingsFormat(name=Lucene41WithOrds), foo_b=PostingsFormat(name=Memory
doPackFST= false), foo_f=PostingsFormat(name=Memory doPackFST= false),
n_f1=Pulsing41(freqCutoff=16 minBlockSize=9 maxBlockSize=66)},
docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=DefaultSimilarity,
locale=de_CH, timezone=Asia/Saigon
[junit4] 2> NOTE: Linux 3.13.0-32-generic i386/Oracle Corporation 1.7.0_65
(32-bit)/cpus=8,threads=1,free=399639880,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [SortByFunctionTest,
BinaryUpdateRequestHandlerTest, CollectionsAPIDistributedZkTest,
ConvertedLegacyTest, FieldAnalysisRequestHandlerTest, CursorPagingTest,
OpenCloseCoreStressTest, HdfsBasicDistributedZkTest, OverseerRolesTest,
LegacyHTMLStripCharFilterTest, AutoCommitTest,
HdfsWriteToMultipleCollectionsTest, TestCollationField, TestFunctionQuery,
TestBinaryField, TestSimpleQParserPlugin, UniqFieldsUpdateProcessorFactoryTest,
DocValuesTest, PrimUtilsTest, URLClassifyProcessorTest, TestStressLucene,
CoreAdminRequestStatusTest, DistributedFacetPivotLongTailTest,
TestSweetSpotSimilarityFactory, HdfsCollectionsAPIDistributedZkTest,
CurrencyFieldXmlFileTest, TestMissingGroups, TestFieldSortValues,
OutputWriterTest, TestCloudInspectUtil, TestSchemaVersionResource,
DebugComponentTest, RequestHandlersTest, TestGroupingSearch, TestCustomSort,
ScriptEngineTest, TestDocBasedVersionConstraints, TestStandardQParsers,
TermVectorComponentDistributedTest, DateFieldTest, TestSearcherReuse,
ChaosMonkeySafeLeaderTest, DirectSolrConnectionTest, CircularListTest,
DirectUpdateHandlerOptimizeTest, TestLazyCores, TestAddFieldRealTimeGet,
AnalysisErrorHandlingTest, BasicDistributedZk2Test,
LeaderElectionIntegrationTest, TestImplicitCoreProperties, ExpressionTest,
AddSchemaFieldsUpdateProcessorFactoryTest, TestReversedWildcardFilterFactory,
TestCollationFieldDocValues, SolrInfoMBeanTest,
DistributedQueryElevationComponentTest, TestNonNRTOpen, TestManagedResource,
RAMDirectoryFactoryTest, TestSolrQueryParserDefaultOperatorResource, TestJoin,
TestLeaderElectionZkExpiry, MigrateRouteKeyTest, TestClassNameShortening,
CoreMergeIndexesAdminHandlerTest, SolrRequestParserTest,
TestIndexingPerformance, DistributedDebugComponentTest, TestFiltering,
UpdateRequestProcessorFactoryTest, CursorMarkTest, MultiTermTest,
TestCharFilters, UUIDFieldTest, SolrIndexConfigTest,
TestSolrQueryParserResource, DistribDocExpirationUpdateProcessorTest,
TestInitQParser, TestQueryTypes, TestIntervalFaceting,
DistributedQueryComponentCustomSortTest, HardAutoCommitTest,
SynonymTokenizerTest, SolrXmlInZkTest, SearchHandlerTest,
TestSchemaSimilarityResource, SolrPluginUtilsTest, TestUpdate,
TestRandomFaceting, TestExceedMaxTermLength, QueryParsingTest, TestSolrXml,
TestZkChroot, TestHighlightDedupGrouping, TestSolrXmlPersistence,
DistributedTermsComponentTest, SolrCoreTest, FileBasedSpellCheckerTest,
AbstractAnalyticsStatsTest, AnalysisAfterCoreReloadTest, PolyFieldTest,
TermVectorComponentTest, QueryElevationComponentTest, CacheHeaderTest,
BasicDistributedZkTest, BasicZkTest, FullSolrCloudDistribCmdsTest,
ZkSolrClientTest, TestRandomDVFaceting, ShardRoutingCustomTest,
TestDistributedSearch]
[junit4] Completed on J1 in 14.63s, 1 test, 1 failure <<< FAILURES!
[...truncated 641 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:474: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:454: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following
error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The
following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1350:
The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:965:
There were test failures: 430 suites, 1782 tests, 1 error, 1 failure, 40
ignored (19 assumptions)
Total time: 93 minutes 17 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.7.0_65 -server
-XX:+UseConcMarkSweepGC
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]
