You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/03/24 17:29:18 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_60-ea-b10) - Build
# 9786 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9786/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.client.solrj.impl.CloudSolrServerTest.testDistribSearch
Error Message:
java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:53990 within 45000 ms
Stack Trace:
org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:53990 within 45000 ms
at __randomizedtesting.SeedInfo.seed([E7564D880925D0D5:66B0C3907E7AB0E9]:0)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:91)
at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:85)
at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:77)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:201)
at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:95)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:860)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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 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:70)
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:359)
at java.lang.Thread.run(Thread.java:744)
Caused by: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:53990 within 45000 ms
at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
... 45 more
Build Log:
[...truncated 11811 lines...]
[junit4] Suite: org.apache.solr.client.solrj.impl.CloudSolrServerTest
[junit4] 2> 18949 T106 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 18950 T106 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /sm_/
[junit4] 2> 18952 T106 oasc.AbstractZkTestCase.<clinit> WARN TEST_HOME() does not exist - solrj test?
[junit4] 2> 18956 T106 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-solrj/test/J0/./solrtest-CloudSolrServerTest-1395678444703
[junit4] 2> 18959 T106 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 18960 T107 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 19060 T106 oasc.ZkTestServer.run start zk server on port:53990
[junit4] 2> 19092 T106 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 71338 T110 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 52230ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 71339 T106 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 71358 T108 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4eafcd90000, 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:744)
[junit4] 2>
[junit4] 2> 71361 T108 oazs.NIOServerCnxnFactory.run WARN Ignoring unexpected runtime exception java.nio.channels.CancelledKeyException
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
[junit4] 2> at sun.nio.ch.SelectionKeyImpl.readyOps(SelectionKeyImpl.java:87)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:187)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 71362 T108 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f4eafcd90002, 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:744)
[junit4] 2>
[junit4] 2> 71368 T106 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53990 53990
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CloudSolrServerTest -Dtests.method=testDistribSearch -Dtests.seed=E7564D880925D0D5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=is -Dtests.timezone=America/Antigua -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 52.6s J0 | CloudSolrServerTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:53990 within 45000 ms
[junit4] > at __randomizedtesting.SeedInfo.seed([E7564D880925D0D5:66B0C3907E7AB0E9]:0)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:150)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:101)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:91)
[junit4] > at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:91)
[junit4] > at org.apache.solr.cloud.AbstractZkTestCase.buildZooKeeper(AbstractZkTestCase.java:85)
[junit4] > at org.apache.solr.cloud.AbstractDistribZkTestBase.setUp(AbstractDistribZkTestBase.java:77)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.setUp(AbstractFullDistribZkTestBase.java:201)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServerTest.setUp(CloudSolrServerTest.java:95)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] > Caused by: java.util.concurrent.TimeoutException: Could not connect to ZooKeeper 127.0.0.1:53990 within 45000 ms
[junit4] > at org.apache.solr.common.cloud.ConnectionManager.waitForConnected(ConnectionManager.java:223)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:142)
[junit4] > ... 45 more
[junit4] IGNOR/A 0.01s J0 | CloudSolrServerTest.testShutdown
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-5880))
[junit4] 2> 71582 T106 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 52638 T105 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=is, timezone=America/Antigua
[junit4] 2> NOTE: Linux 3.8.0-37-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=1,free=78044560,total=126484480
[junit4] 2> NOTE: All tests run in this JVM: [TestXMLEscaping, TestRetryUtil, JettyWebappTest, SolrExampleEmbeddedTest, TestCoreAdmin, TestEmbeddedSolrServer, SolrParamTest, ClientUtilsTest, TestUpdateRequestCodec, ModifiableSolrParamsTest, LargeVolumeEmbeddedTest, ContentStreamTest, DocumentAnalysisResponseTest, CloudSolrServerTest]
[junit4] Completed on J0 in 53.42s, 2 tests, 1 error, 1 skipped <<< FAILURES!
[...truncated 100 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 49 suites, 284 tests, 1 error, 1 ignored (1 assumption)
Total time: 54 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b10 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_60-ea-b10) - Build
# 9787 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9787/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([597100C9B8403A54:5D798F3AAAE5D575]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
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:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
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 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:70)
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:359)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 45 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 46 more
Build Log:
[...truncated 10351 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 243703 T1279 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 243703 T1279 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1395684116946
[junit4] 2> 243704 T1279 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 243708 T1279 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 243708 T1279 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 243708 T1280 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 243808 T1279 oasc.ZkTestServer.run start zk server on port:57474
[junit4] 2> 243809 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243866 T1286 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13b24faa name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243866 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243866 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243868 T1288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b55f98f name:ZooKeeperConnection Watcher:127.0.0.1:57474 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243869 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243874 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243880 T1290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50d6a7db name:ZooKeeperConnection Watcher:127.0.0.1:57474 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243881 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243881 T1279 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 243886 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 243891 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243892 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243892 T1293 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@685818e1 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243893 T1295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b13103d name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243893 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243893 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243893 T1279 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 243894 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 243897 T1279 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 243897 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 243898 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 243900 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 243901 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 243901 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 243903 T1291 oasc.Overseer.start Overseer (id=91467554288631811-127.0.0.1:57474_solr-n_0000000000) starting
[junit4] 2> 243903 T1279 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 243908 T1295 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 243909 T1291 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 243916 T1291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 243923 T1291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 243931 T1291 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 243934 T1291 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 243943 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 243943 T1297 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 243944 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 243946 T1299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49895a3 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 243946 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 243947 T1297 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91467554288631811-127.0.0.1:57474_solr-n_0000000000) am no longer a leader.
[junit4] 2> 243947 T1297 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 243948 T1297 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:225)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:222)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:222)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:297)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:211)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 243956 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 243956 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 243958 T1291 oasc.Overseer.start Overseer (id=91467554288631813-127.0.0.1:57474_solr-n_0000000001) starting
[junit4] 2> 243979 T1301 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 243980 T1301 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 243980 T1300 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 243984 T1300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 243984 T1300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 243984 T1300 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 243985 T1300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 243988 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 243989 T1295 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> 244406 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 244413 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 244419 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244420 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244420 T1300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 244420 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 244424 T1300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 244424 T1300 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 244428 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 244428 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244429 T1303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7708e278 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 244429 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 244430 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 244432 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 244434 T1295 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 244434 T1303 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 244435 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244435 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 244437 T1300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 244437 T1300 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 244439 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244441 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 244544 T1303 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 244544 T1295 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 244642 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 244644 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244645 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244645 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244646 T1300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 244647 T1300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 244647 T1300 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 244647 T1300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 244651 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 244755 T1303 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 244755 T1295 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245145 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245152 T1303 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245153 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245153 T1303 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 245158 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245158 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245158 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245159 T1300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245161 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245263 T1303 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> 245354 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245357 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245362 T1305 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@230acb0e name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245363 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245365 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 245369 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 245375 T1303 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245378 T1305 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245379 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245379 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245379 T1299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245380 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245380 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 245382 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245383 T1307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@196272bb name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245383 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245388 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 245388 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 245390 T1291 oasc.Overseer.start Overseer (id=91467554288631816-127.0.0.1:57474_solr-n_0000000002) starting
[junit4] 2> 245392 T1303 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245393 T1305 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245396 T1305 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 245397 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245409 T1309 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 245410 T1309 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 245411 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245412 T1311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@556fbbd4 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245412 T1308 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 245412 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245413 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 245415 T1308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245416 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245416 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245417 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 245424 T1305 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245425 T1311 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245427 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245427 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245428 T1305 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245428 T1311 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245432 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245434 T1308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245435 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245435 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245437 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245440 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245441 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245441 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245447 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245549 T1305 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245549 T1311 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245634 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245637 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245637 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245637 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245637 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245640 T1308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245641 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 245641 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245642 T1311 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245642 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245643 T1311 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 245644 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245647 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245651 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245753 T1311 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> 245844 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245845 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245846 T1313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ba8cef name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245846 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245847 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 245849 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 245850 T1311 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245852 T1313 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245853 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245853 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245853 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245853 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245854 T1308 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245854 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245854 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245856 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245857 T1313 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245857 T1311 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 245858 T1313 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 245859 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245859 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245860 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245860 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245863 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245867 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245868 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245869 T1315 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10383352 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245869 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245870 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 245872 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 245874 T1315 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245876 T1313 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 245877 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245877 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 245878 T1308 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245878 T1308 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245880 T1307 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 245882 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245909 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 245911 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 245912 T1317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6887c617 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 245912 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 245915 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 245915 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 245917 T1291 oasc.Overseer.start Overseer (id=91467554288631820-127.0.0.1:57474_solr-n_0000000003) starting
[junit4] 2> 245934 T1319 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 245935 T1319 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 245936 T1318 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 245937 T1318 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 245937 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245937 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245939 T1315 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245939 T1313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245943 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245943 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245944 T1315 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245944 T1313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245946 T1315 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245948 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 245948 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 245948 T1313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245948 T1315 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 245950 T1318 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 246083 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246085 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246085 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246087 T1318 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246088 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 246088 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246090 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246091 T1313 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246092 T1315 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246092 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246093 T1315 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 246098 T1315 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> 246098 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246100 T1318 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246101 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246203 T1315 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> 246293 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246294 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246296 T1321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@616b6b71 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246296 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246299 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 246301 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 246302 T1315 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246303 T1321 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246305 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246305 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246305 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246306 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246309 T1318 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246310 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246310 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246315 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246317 T1315 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246317 T1321 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246318 T1321 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 246319 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246319 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246321 T1318 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246321 T1318 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246329 T1317 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246334 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 246338 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246340 T1323 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40137bc5 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246340 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246341 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246343 T1325 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2744256a name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246343 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246345 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 246346 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 246346 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 246348 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 246349 T1291 oasc.Overseer.start Overseer (id=91467554288631822-127.0.0.1:57474_solr-n_0000000004) starting
[junit4] 2> 246351 T1325 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246352 T1321 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246355 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246363 T1327 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 246363 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246364 T1327 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 246365 T1326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246365 T1326 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 246366 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246366 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246367 T1321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246368 T1325 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246369 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246370 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246370 T1321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246370 T1325 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246373 T1321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246373 T1325 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246375 T1326 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 246376 T1326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246378 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246379 T1321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246379 T1325 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246382 T1326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246382 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246382 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246384 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246486 T1321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246486 T1325 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246565 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246567 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246567 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246568 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246568 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246569 T1326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246570 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 246570 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246571 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246577 T1321 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246577 T1325 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246578 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246579 T1325 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 246585 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246589 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246652 T1295 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 246652 T1295 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 246653 T1295 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 246689 T1325 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> 246781 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246782 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246785 T1329 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@da7d7b5 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246785 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246786 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 246788 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 246791 T1325 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246791 T1329 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246793 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246793 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246793 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246794 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246795 T1326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246795 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246795 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246797 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246805 T1325 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246806 T1329 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 246807 T1329 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 246811 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246811 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246817 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246818 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246821 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246831 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246838 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246838 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246838 T1331 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26e50fe5 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246838 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246839 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 246842 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 246844 T1331 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246846 T1329 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 246848 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246848 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 246849 T1326 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246849 T1326 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246851 T1323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 246855 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246863 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 246866 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246867 T1333 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3decdd7c name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 246868 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 246877 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 246877 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 246879 T1291 oasc.Overseer.start Overseer (id=91467554288631826-127.0.0.1:57474_solr-n_0000000005) starting
[junit4] 2> 246898 T1335 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 246899 T1335 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 246900 T1334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 246903 T1334 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 246904 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246904 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246905 T1329 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246905 T1331 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246908 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246908 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246909 T1329 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246911 T1329 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246913 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 246913 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 246914 T1331 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246915 T1329 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 246917 T1334 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 247056 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247058 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247059 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 247060 T1334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247060 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 247060 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247064 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247065 T1331 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 247065 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247066 T1331 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 247069 T1331 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> 247069 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247070 T1334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247073 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247142 T1305 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 247142 T1305 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 247142 T1305 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[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> 247176 T1331 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> 247266 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247267 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 247269 T1337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4208aee0 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 247269 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 247270 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 247272 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 247274 T1331 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 247274 T1337 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 247276 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247276 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 247276 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247276 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247277 T1334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247278 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 247278 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247280 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247285 T1331 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 247285 T1337 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 247286 T1337 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 247287 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247287 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 247289 T1334 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 247289 T1334 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247291 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247293 T1333 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247294 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 247296 T1339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@464dfa23 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 247296 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 247297 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 247298 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 247299 T1291 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 247299 T1291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 247301 T1341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71fcb346 name:ZooKeeperConnection Watcher:127.0.0.1:57474/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 247302 T1337 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 247302 T1339 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 247302 T1291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 247304 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 247307 T1291 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57474_solr
[junit4] 2> 247307 T1291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 247308 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247308 T1291 oasc.Overseer.start Overseer (id=91467554288631829-127.0.0.1:57474_solr-n_0000000006) starting
[junit4] 2> 247316 T1343 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 247316 T1343 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 247318 T1342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247319 T1342 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 247319 T1342 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 247319 T1342 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247320 T1339 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247320 T1337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247325 T1342 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 247325 T1342 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247326 T1337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247327 T1339 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247329 T1339 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247329 T1337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247331 T1342 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 247332 T1342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247333 T1342 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 247333 T1342 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247336 T1341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247336 T1339 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247336 T1337 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 247509 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247511 T1341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247511 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 247512 T1342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 247513 T1342 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 247513 T1342 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 247516 T1341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 247517 T1337 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 247518 T1337 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(So
[...truncated too long message...]
m going to be the leader 127.0.0.1:34498_solr
[junit4] 2> 287900 T1279 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 287901 T1279 oasc.Overseer.start Overseer (id=91467557083873284-127.0.0.1:34498_solr-n_0000000000) starting
[junit4] 2> 287903 T1279 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 287904 T1279 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 287906 T1279 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 287908 T1279 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 287909 T1279 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 287911 T1279 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 287915 T1756 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 287916 T1756 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 287917 T1755 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 287919 T1755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 287919 T1755 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> 287919 T1755 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 287920 T1755 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 287922 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287922 T1743 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> 287922 T1752 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> 288418 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 288427 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 288430 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288431 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 288431 T1755 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 288432 T1752 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 288432 T1743 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 288433 T1279 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 288434 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288434 T1758 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74c26102 name:ZooKeeperConnection Watcher:127.0.0.1:34498/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 288435 T1279 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 288435 T1279 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 288436 T1279 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 288438 T1758 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 288438 T1743 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 288440 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288440 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 288441 T1755 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> 288441 T1755 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 288443 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288444 T1279 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 288447 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288449 T1754 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 288550 T1743 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> 288550 T1758 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> 288551 T1279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 288553 T1743 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 288555 T1279 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34498 34498
[junit4] 2> 288617 T1279 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 288618 T1279 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 288618 T1279 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 290053 T1758 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 291618 T1279 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=th_TH_TH_#u-nu-thai, timezone=Europe/Tirane
[junit4] 2> NOTE: Linux 3.8.0-37-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=1,free=218933232,total=280494080
[junit4] 2> NOTE: All tests run in this JVM: [TestTrie, TestHighlightDedupGrouping, ResourceLoaderTest, SliceStateUpdateTest, QueryParsingTest, TriLevelCompositeIdRoutingTest, TermsComponentTest, SliceStateTest, TestCharFilters, TestDefaultSearchFieldResource, SampleTest, SystemInfoHandlerTest, LegacyHTMLStripCharFilterTest, TestBM25SimilarityFactory, TestCursorMarkWithoutUniqueKey, TestGroupingSearch, DeleteInactiveReplicaTest, SpatialFilterTest, TestSolrIndexConfig, TestRemoteStreaming, TestFieldCollectionResource, TestMergePolicyConfig, TestPHPSerializedResponseWriter, TestSort, TestSolrXMLSerializer, TestComplexPhraseQParserPlugin, TestFunctionQuery, TestExtendedDismaxParser, TestFileDictionaryLookup, TestRequestStatusCollectionAPI, CursorMarkTest, RecoveryZkTest, DocValuesTest, TestLRUCache, TestMaxScoreQueryParser, ParsingFieldUpdateProcessorsTest, DirectUpdateHandlerOptimizeTest, MBeansHandlerTest, TestFreeTextSuggestions, SpellPossibilityIteratorTest, CircularListTest, SoftAutoCommitTest, TestCollationKeyRangeQueries, LukeRequestHandlerTest, TestSearchPerf, TestSimpleQParserPlugin, ReturnFieldsTest, TestValueSourceCache, OverseerTest]
[junit4] Completed on J0 in 47.94s, 9 tests, 1 error <<< FAILURES!
[...truncated 904 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 379 suites, 1601 tests, 1 error, 37 ignored (16 assumptions)
Total time: 50 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure