Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/940/
4 tests failed. FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Timeout occured while waiting response from server at: http://127.0.0.1:36747/_ Stack Trace: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:36747/_ at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:588) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.makeRequest(CollectionsAPIDistributedZkTest.java:382) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testErrorHandling(CollectionsAPIDistributedZkTest.java:498) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test(CollectionsAPIDistributedZkTest.java:169) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:964) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:939) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:482) ... 47 more FAILED: org.apache.solr.cloud.OverseerTest.testShardLeaderChange 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([3132EE27F7365D16:EF6169D0EDAEA8E7]:0) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:212) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:173) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:138) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:310) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:219) at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:181) at org.apache.solr.cloud.OverseerTest.testShardLeaderChange(OverseerTest.java:841) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) at org.apache.zookeeper.ZooKeeper.multiInternal(ZooKeeper.java:949) at org.apache.zookeeper.ZooKeeper.multi(ZooKeeper.java:915) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:577) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:574) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) at org.apache.solr.common.cloud.SolrZkClient.multi(SolrZkClient.java:574) at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:195) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:49) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:42) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:178) ... 45 more FAILED: org.apache.solr.cloud.UnloadDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=28745, name=testExecutor-3446-thread-1, state=RUNNABLE, group=TGRP-UnloadDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=28745, name=testExecutor-3446-thread-1, state=RUNNABLE, group=TGRP-UnloadDistributedZkTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:59379 at __randomizedtesting.SeedInfo.seed([3132EE27F7365D16]:0) at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:586) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:231) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:59379 at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:588) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:584) ... 4 more Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:482) ... 8 more FAILED: org.apache.solr.cloud.hdfs.HdfsUnloadDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=53995, name=testExecutor-8334-thread-5, state=RUNNABLE, group=TGRP-HdfsUnloadDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=53995, name=testExecutor-8334-thread-5, state=RUNNABLE, group=TGRP-HdfsUnloadDistributedZkTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:38186 at __randomizedtesting.SeedInfo.seed([3132EE27F7365D16]:0) at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:586) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:231) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:38186 at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:588) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:230) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.BasicDistributedZkTest$1.run(BasicDistributedZkTest.java:584) ... 4 more Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:482) ... 8 more Build Log: [...truncated 11180 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.cloud.OverseerTest_3132EE27F7365D16-001/init-core-data-001 [junit4] 2> 563027 INFO (SUITE-OverseerTest-seed#[3132EE27F7365D16]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) [junit4] 2> 563027 INFO (SUITE-OverseerTest-seed#[3132EE27F7365D16]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore [junit4] 2> 563027 INFO (SUITE-OverseerTest-seed#[3132EE27F7365D16]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end [junit4] 2> 563034 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDoubleAssignment [junit4] 2> 563034 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 563043 INFO (Thread-9027) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 563043 INFO (Thread-9027) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 563143 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer start zk server on port:59633 [junit4] 2> 563143 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563156 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563189 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4fdc20a8 name:ZooKeeperConnection Watcher:127.0.0.1:59633/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563189 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563189 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563189 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563196 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563198 INFO (zkCallback-572-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1b3d31fb name:ZooKeeperConnection Watcher:127.0.0.1:59633 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563198 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563198 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563204 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563213 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563220 INFO (zkCallback-573-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3d30e940 name:ZooKeeperConnection Watcher:127.0.0.1:59633 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563220 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563220 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563221 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 563223 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 563225 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 563227 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 563228 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 563230 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 563231 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 563233 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 563234 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563242 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563256 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@416d1ec6 name:ZooKeeperConnection Watcher:127.0.0.1:59633/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563256 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563257 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563258 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 563269 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 563269 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 563271 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 563271 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 563272 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563272 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563272 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563280 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563296 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@56d62a7 name:ZooKeeperConnection Watcher:127.0.0.1:59633/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563296 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563296 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563296 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 563302 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 563303 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 563304 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 563304 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95429763940089860-127.0.0.1:59633_solr-n_0000000000 [junit4] 2> 563304 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:59633_solr [junit4] 2> 563304 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 563305 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=95429763940089860-127.0.0.1:59633_solr-n_0000000000) starting [junit4] 2> 563306 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 563307 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 563308 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 563310 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 563311 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 563312 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 563314 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 563317 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 563331 INFO (OverseerCollectionConfigSetProcessor-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 563349 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 563351 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563352 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 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/"} current state version: 0 [junit4] 2> 563352 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator 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> 563352 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 563353 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 563354 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563355 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563356 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563846 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 563847 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 563847 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 563914 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 563941 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/95429763940089859-node1_core1-n_0000000000 [junit4] 2> 563942 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 563945 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/95429763940089859-node1_core1-n_0000000000 [junit4] 2> 563960 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/";, [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 563971 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 563972 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563972 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563972 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 563972 INFO (zkCallback-574-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 563972 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 563974 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 563974 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 563985 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 563986 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2ceda2fe name:ZooKeeperConnection Watcher:127.0.0.1:59633/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 563986 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 563986 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 563989 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 563990 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 563990 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 563991 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 563991 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 563992 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563992 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 563992 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563993 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 563993 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 563994 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 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/"} current state version: 1 [junit4] 2> 563994 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator 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> 563994 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 563996 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/95429763940089861-node1_core1-n_0000000001 [junit4] 2> 563996 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/95429763940089861-node1_core1-n_0000000001 [junit4] 2> 563998 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/";, [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 564108 INFO (zkCallback-575-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 564112 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 564118 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 564140 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (1) [junit4] 2> 564147 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 564147 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [1]) [junit4] 2> 564148 INFO (zkCallback-571-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 564148 INFO (zkCallback-578-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 564149 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15308dd5ca60005, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 564151 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59633 59633 [junit4] 2> 564329 INFO (Thread-9027) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59633 59633 [junit4] 2> 564330 WARN (Thread-9027) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 4 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 4 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 4 /solr/live_nodes [junit4] 2> 4 /solr/collections [junit4] 2> [junit4] 2> 564330 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDoubleAssignment [junit4] 2> 564330 INFO (TEST-OverseerTest.testDoubleAssignment-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=95429763940089860-127.0.0.1:59633_solr-n_0000000000) closing [junit4] 2> 564333 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRemovalOfLastReplica [junit4] 2> 564334 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 564353 INFO (OverseerStateUpdate-95429763940089860-127.0.0.1:59633_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:59633_solr [junit4] 2> 564357 INFO (Thread-9028) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 564357 INFO (Thread-9028) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 564358 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 564453 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer start zk server on port:47700 [junit4] 2> 564453 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 564461 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 564465 INFO (zkCallback-579-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2102e4fe name:ZooKeeperConnection Watcher:127.0.0.1:47700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 564471 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 564471 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 564473 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 564478 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 564483 INFO (zkCallback-580-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6a70d355 name:ZooKeeperConnection Watcher:127.0.0.1:47700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 564483 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 564483 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 564483 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 564490 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 564491 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 564491 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2e610d18 name:ZooKeeperConnection Watcher:127.0.0.1:47700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 564491 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 564492 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 564492 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 564493 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 564494 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 564495 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 564497 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 564498 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 564499 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 564500 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 564504 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 564521 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@54d9c9ca name:ZooKeeperConnection Watcher:127.0.0.1:47700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 564521 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 564521 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 564522 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 564524 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 564526 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 564527 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 564528 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95429764025417731-127.0.0.1:47700_solr-n_0000000000 [junit4] 2> 564528 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:47700_solr [junit4] 2> 564528 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 564529 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=95429764025417731-127.0.0.1:47700_solr-n_0000000000) starting [junit4] 2> 564530 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 564532 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 564535 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 564545 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 564546 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 564547 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 564557 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 564573 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 564576 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 564576 INFO (OverseerCollectionConfigSetProcessor-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 564590 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 564590 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 564592 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"create", [junit4] 2> "name":"collection1", [junit4] 2> "numShards":"2", [junit4] 2> "replicationFactor":"1", [junit4] 2> "maxShardsPerNode":"4"} current state version: 0 [junit4] 2> 564592 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 564593 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564600 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564641 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 564642 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 564642 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 564650 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 3, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 564650 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 564652 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 3, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 564652 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard1", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 564653 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 3, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 1 [junit4] 2> 564653 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "shard":"shard2", [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 564755 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564755 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564809 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 564809 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 564809 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node1 is already registered [junit4] 2> 564809 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 564811 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 564811 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core4", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 564811 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node2 is already registered [junit4] 2> 564811 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard2 is already registered [junit4] 2> 564812 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 564813 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 564813 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node3 is already registered [junit4] 2> 564813 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 564814 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 564814 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr";, [junit4] 2> "node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 564814 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node4 is already registered [junit4] 2> 564814 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard2 is already registered [junit4] 2> 564925 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564925 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 564985 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "collection":"collection1", [junit4] 2> "core_node_name":"core_node3"} current state version: 3 [junit4] 2> 565087 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565087 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565132 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "collection":"collection1", [junit4] 2> "core_node_name":"core_node4"} current state version: 4 [junit4] 2> 565234 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565234 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565239 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "collection":"collection1", [junit4] 2> "core_node_name":"core_node1"} current state version: 5 [junit4] 2> 565341 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565342 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565350 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "collection":"collection1", [junit4] 2> "core_node_name":"core_node2"} current state version: 6 [junit4] 2> 565452 INFO (zkCallback-581-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565452 INFO (zkCallback-582-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0]) [junit4] 2> 565510 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15308dd61bc0002, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 565511 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47700 47700 [junit4] 2> 565801 INFO (Thread-9028) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47700 47700 [junit4] 2> 565802 WARN (Thread-9028) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 2 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 2 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 2 /solr/live_nodes [junit4] 2> 2 /solr/collections [junit4] 2> [junit4] 2> 565802 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRemovalOfLastReplica [junit4] 2> 565802 INFO (TEST-OverseerTest.testRemovalOfLastReplica-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=95429764025417731-127.0.0.1:47700_solr-n_0000000000) closing [junit4] 2> 565804 INFO (OverseerStateUpdate-95429764025417731-127.0.0.1:47700_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:47700_solr [junit4] 2> 565820 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadQueueItem [junit4] 2> 565820 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 565821 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:350) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:308) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:267) [junit4] 2> 565832 INFO (Thread-9029) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 565832 INFO (Thread-9029) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 565921 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ZkTestServer start zk server on port:52976 [junit4] 2> 565921 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 565921 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 565954 INFO (zkCallback-585-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3a38e994 name:ZooKeeperConnection Watcher:127.0.0.1:52976 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 565954 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 565954 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 565956 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 565962 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 565970 INFO (zkCallback-586-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6fdf3a48 name:ZooKeeperConnection Watcher:127.0.0.1:52976 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 565970 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 565970 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 565970 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 565980 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 566012 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 566016 INFO (zkCallback-587-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4da89415 name:ZooKeeperConnection Watcher:127.0.0.1:52976/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 566016 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 566017 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 566023 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 566024 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 566025 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 566026 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 566026 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 566027 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 566032 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 566052 INFO (zkCallback-588-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1df7eddf name:ZooKeeperConnection Watcher:127.0.0.1:52976/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 566052 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 566053 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 566053 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 566068 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 566069 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 566070 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 566070 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/95429764121690115-127.0.0.1:52976_solr-n_0000000000 [junit4] 2> 566070 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52976_solr [junit4] 2> 566071 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 566072 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.Overseer Overseer (id=95429764121690115-127.0.0.1:52976_solr-n_0000000000) starting [junit4] 2> 566072 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 566084 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 566086 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 566087 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 566088 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 566089 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 566091 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 566092 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 566093 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 566094 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 566095 INFO (OverseerCollectionConfigSetProcessor-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 566122 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 566131 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 566131 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 566166 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 566175 INFO (zkCallback-591-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@37a76fb4 name:ZooKeeperConnection Watcher:127.0.0.1:52976/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 566175 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 566175 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 566176 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 566177 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (0) [junit4] 2> 566178 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1 [junit4] 2> 566179 INFO (zkCallback-588-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 566179 INFO (zkCallback-587-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 566179 INFO (zkCallback-591-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes], has occurred - updating... (live nodes size: [0]) [junit4] 2> 566180 INFO (zkCallback-588-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 566180 INFO (zkCallback-587-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 566180 INFO (zkCallback-591-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 566181 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 0 [junit4] 2> 566182 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 566182 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 566182 INFO (OverseerStateUpdate-95429764121690115-127.0.0.1:52976_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 566184 INFO (zkCallback-588-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 566184 INFO (zkCallback-587-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 566185 INFO (zkCallback-591-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [1]) [junit4] 2> 566681 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 566682 INFO (zkCallback-588-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 566682 INFO (zkCallback-587-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 566683 INFO (zkCallback-591-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating... [junit4] 2> 566685 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard2/election/95429764121690116-127.0.0.1_core1-n_0000000000 [junit4] 2> 566686 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard2 [junit4] 2> 566687 INFO (TEST-OverseerTest.testBadQueueItem-seed#[3132EE27F7365D16]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard2/leader after winning as /collections/collection1/leader_elect/shard2/election/954297641 [...truncated too long message...] [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:497) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:834) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> Caused by: java.lang.NullPointerException [junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:198) [junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291) [junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223) [junit4] 2> ... 54 more [junit4] 2> 4421254 INFO (SUITE-HdfsUnloadDistributedZkTest-seed#[3132EE27F7365D16]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> Feb 22, 2016 1:08:16 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene60): {other_tl1=BlockTreeOrds(blocksize=128), range_facet_l_dv=FST50, _version_=BlockTreeOrds(blocksize=128), multiDefault=PostingsFormat(name=Asserting), a_t=PostingsFormat(name=Asserting), intDefault=BlockTreeOrds(blocksize=128), a_i1=PostingsFormat(name=Asserting), id=FST50, range_facet_i_dv=PostingsFormat(name=Asserting), text=Lucene50(blocksize=128), range_facet_l=PostingsFormat(name=Asserting), timestamp=PostingsFormat(name=Asserting)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene54), range_facet_i_dv=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=sq-AL, timezone=US/East-Indiana [junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_66 (64-bit)/cpus=4,threads=2,free=152163120,total=525860864 [junit4] 2> NOTE: All tests run in this JVM: [HdfsLockFactoryTest, TestPostingsSolrHighlighter, TestCloudSchemaless, CoreAdminHandlerTest, TestUtils, TestRecovery, TestSolrQueryParser, TestChildDocTransformer, RecoveryAfterSoftCommitTest, CloudMLTQParserTest, TestSort, TestDynamicLoading, BadIndexSchemaTest, HighlighterConfigTest, TestFuzzyAnalyzedSuggestions, TestFieldTypeResource, TestSweetSpotSimilarityFactory, CoreMergeIndexesAdminHandlerTest, TestJmxMonitoredMap, TestBulkSchemaAPI, FieldAnalysisRequestHandlerTest, SparseHLLTest, FieldMutatingUpdateProcessorTest, SolrCoreCheckLockOnStartupTest, TestCoreDiscovery, HdfsChaosMonkeyNothingIsSafeTest, CleanupOldIndexTest, OverseerRolesTest, MergeStrategyTest, TestCloudPivotFacet, TestSchemaManager, TestCollationField, DistribCursorPagingTest, OverseerTest, TestExtendedDismaxParser, NoCacheHeaderTest, TestRandomRequestDistribution, SolrTestCaseJ4Test, TestDistributedStatsComponentCardinality, CurrencyFieldXmlFileTest, QueryParsingTest, TestBulkSchemaConcurrent, PreAnalyzedUpdateProcessorTest, TestXIncludeConfig, DebugComponentTest, TestSchemaResource, TestSolrXml, CustomCollectionTest, TestJsonFacets, TestElisionMultitermQuery, DeleteReplicaTest, HttpPartitionTest, TestGroupingSearch, RegexBoostProcessorTest, TestFastWriter, HdfsTlogReplayBufferedWhileIndexingTest, TestJmxIntegration, LeaderInitiatedRecoveryOnShardRestartTest, FullSolrCloudDistribCmdsTest, CircularListTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestIndexingPerformance, CollectionStateFormat2Test, UnloadDistributedZkTest, TestSortByMinMaxFunction, TestTolerantSearch, AssignTest, SegmentsInfoRequestHandlerTest, HardAutoCommitTest, BinaryUpdateRequestHandlerTest, TestLRUStatsCache, LeaderElectionTest, DateMathParserTest, FullHLLTest, PrimitiveFieldTypeTest, SaslZkACLProviderTest, HdfsDirectoryFactoryTest, TestIndexSearcher, DocValuesMissingTest, StatelessScriptUpdateProcessorFactoryTest, HdfsNNFailoverTest, ZkStateWriterTest, TestSolrCLIRunExample, SharedFSAutoReplicaFailoverUtilsTest, TestRawTransformer, TestExceedMaxTermLength, DistributedFacetPivotSmallTest, DocExpirationUpdateProcessorFactoryTest, TestAuthorizationFramework, SearchHandlerTest, TestReload, StressHdfsTest, TestCharFilters, RequestHandlersTest, BadCopyFieldTest, DocValuesMultiTest, BasicDistributedZk2Test, SyncSliceTest, OpenCloseCoreStressTest, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestHashPartitioner, TermVectorComponentDistributedTest, TestRealTimeGet, TestStressReorder, TestStressVersions, TestCoreContainer, SimpleFacetsTest, StatsComponentTest, SolrCmdDistributorTest, TestFunctionQuery, BasicFunctionalityTest, DirectUpdateHandlerTest, HighlighterTest, SoftAutoCommitTest, TestFoldingMultitermQuery, SuggesterTSTTest, TestStressLucene, SpatialFilterTest, TestCSVLoader, TestPseudoReturnFields, QueryEqualityTest, DefaultValueUpdateProcessorTest, TestRemoteStreaming, TestSolrDeletionPolicy1, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, TestQueryTypes, TermsComponentTest, DocumentBuilderTest, MoreLikeThisHandlerTest, RequiredFieldsTest, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, JsonLoaderTest, PingRequestHandlerTest, SOLR749Test, UpdateParamsTest, TestSolrIndexConfig, SolrIndexConfigTest, BadComponentTest, TestStressRecovery, SampleTest, TestDocSet, TestSearchPerf, TestConfig, TestSolrCoreProperties, DirectSolrConnectionTest, SpellPossibilityIteratorTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestBM25SimilarityFactory, ScriptEngineTest, URLClassifyProcessorTest, PluginInfoTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, ClusterStateTest, TestSolrJ, TestDocumentBuilder, SliceStateTest, SystemInfoHandlerTest, UUIDFieldTest, TestRTGBase, DistributedIntervalFacetingTest, TestJettySolrRunner, AliasIntegrationTest, CdcrRequestHandlerTest, DeleteLastCustomShardedReplicaTest, DistributedQueueTest, LeaderInitiatedRecoveryOnCommitTest, MultiThreadedOCPTest, SSLMigrationTest, SharedFSAutoReplicaFailoverTest, TestAuthenticationFramework, TestLeaderInitiatedRecoveryThread, TriLevelCompositeIdRoutingTest, HdfsRecoveryZkTest, HdfsUnloadDistributedZkTest] [junit4] Completed [463/579 (4!)] on J2 in 150.48s, 1 test, 1 error <<< FAILURES! [...truncated 357 lines...] BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:747: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:684: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:59: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:233: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:524: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1457: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1014: There were test failures: 579 suites (8 ignored), 2331 tests, 4 errors, 34 ignored (18 assumptions) [seed: 3132EE27F7365D16] Total time: 226 minutes 54 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts No prior successful build to compare, so performing full copy of artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
