Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/846/
3 tests failed. FAILED: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR Error Message: Captured an uncaught exception in thread: Thread[id=72535, name=coreZkRegister-5993-thread-1, state=RUNNABLE, group=TGRP-LeaderInitiatedRecoveryOnShardRestartTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=72535, name=coreZkRegister-5993-thread-1, state=RUNNABLE, group=TGRP-LeaderInitiatedRecoveryOnShardRestartTest] at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A:549C9DFFA40FFC99]:0) Caused by: java.lang.AssertionError at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A]:0) at org.apache.solr.cloud.ZkController.updateLeaderInitiatedRecoveryState(ZkController.java:2126) at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:451) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:197) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:346) at org.apache.solr.cloud.ZkController.joinElection(ZkController.java:1113) at org.apache.solr.cloud.ZkController.register(ZkController.java:926) at org.apache.solr.cloud.ZkController.register(ZkController.java:881) at org.apache.solr.core.ZkContainer$2.run(ZkContainer.java:183) 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) FAILED: org.apache.solr.cloud.OverseerTest.testOverseerStatsReset Error Message: expected:<0> but was:<1> Stack Trace: java.lang.AssertionError: expected:<0> but was:<1> at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A:214214BE0A773D64]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:472) at org.junit.Assert.assertEquals(Assert.java:456) at org.apache.solr.cloud.OverseerTest.testOverseerStatsReset(OverseerTest.java:732) 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:1660) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:866) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:902) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java: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:875) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:777) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:811) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:822) 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:46) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) 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:54) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=3936, name=collection3, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3936, name=collection3, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:38909/_pal, http://127.0.0.1:41093/_pal, http://127.0.0.1:58007/_pal, http://127.0.0.1:55115/_pal, http://127.0.0.1:40088/_pal] at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A]:0) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:898) Caused by: org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:38909/_pal, http://127.0.0.1:41093/_pal, http://127.0.0.1:58007/_pal, http://127.0.0.1:55115/_pal, http://127.0.0.1:40088/_pal] at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:352) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1099) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1574) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1595) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:888) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:40088/_pal at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:587) 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.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325) ... 7 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:480) ... 11 more Build Log: [...truncated 10321 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_8A16F3829FAD9E6A-001/init-core-data-001 [junit4] 2> 1433642 INFO (SUITE-OverseerTest-seed#[8A16F3829FAD9E6A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) [junit4] 2> 1433642 INFO (SUITE-OverseerTest-seed#[8A16F3829FAD9E6A]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore [junit4] 2> 1433642 INFO (SUITE-OverseerTest-seed#[8A16F3829FAD9E6A]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end [junit4] 2> 1433655 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testOverseerStatsReset [junit4] 2> 1433655 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1433656 INFO (Thread-10971) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1433656 INFO (Thread-10971) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1433756 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer start zk server on port:47509 [junit4] 2> 1433756 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1433779 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1433784 INFO (zkCallback-1030-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@46b7a253 name:ZooKeeperConnection Watcher:127.0.0.1:47509 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1433784 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1433784 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1433786 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1433791 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1433794 INFO (zkCallback-1031-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@14f36161 name:ZooKeeperConnection Watcher:127.0.0.1:47509 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1433794 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1433795 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1433795 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1433797 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1433808 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1433811 INFO (zkCallback-1032-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@25cac5b0 name:ZooKeeperConnection Watcher:127.0.0.1:47509/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1433811 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1433812 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1433812 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1433813 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1433814 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1433815 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1433816 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1433817 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1433819 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1433823 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1433830 INFO (zkCallback-1033-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4f0bc3e8 name:ZooKeeperConnection Watcher:127.0.0.1:47509/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1433830 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1433830 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1433831 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1433833 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 1433836 INFO (zkCallback-1033-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> 1433836 INFO (zkCallback-1032-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> 1433837 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1433840 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1433841 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1433842 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1433842 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94829315767402498-127.0.0.1:47509_solr-n_0000000000 [junit4] 2> 1433843 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:47509_solr [junit4] 2> 1433843 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1433844 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315767402498-127.0.0.1:47509_solr-n_0000000000) starting [junit4] 2> 1433845 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1433846 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1433848 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1433849 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1433851 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1433852 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1433854 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1433858 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1433867 INFO (OverseerCollectionConfigSetProcessor-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1433869 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 0, 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> 1433870 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_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> 1433870 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1433870 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1433871 INFO (zkCallback-1033-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> 1433871 INFO (zkCallback-1032-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> 1434369 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1434370 INFO (zkCallback-1033-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1434370 INFO (zkCallback-1032-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1434373 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/94829315767402499-node1_core1-n_0000000000 [junit4] 2> 1434374 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1434376 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1434381 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315767402498-127.0.0.1:47509_solr-n_0000000000) closing [junit4] 2> 1434381 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ElectionContext Canceling election /overseer_elect/election/94829315767402498-127.0.0.1:47509_solr-n_0000000000 [junit4] 2> 1434383 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:47509_solr [junit4] 2> 1434389 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94829315767402498-127.0.0.1:47509_solr-n_0000000001 [junit4] 2> 1434389 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting , but I'm still the leader [junit4] 2> 1434389 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:47509_solr [junit4] 2> 1434389 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1434391 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315767402498-127.0.0.1:47509_solr-n_0000000001) starting [junit4] 2> 1434400 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1434419 INFO (OverseerCollectionConfigSetProcessor-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1434419 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1434421 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "node_name":"node1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "core":"core1"} current state version: 1 [junit4] 2> 1434421 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "node_name":"node1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "core":"core1"} [junit4] 2> 1434422 INFO (zkCallback-1033-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> 1434423 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 2, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1"} current state version: 2 [junit4] 2> 1434434 INFO (zkCallback-1033-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> 1434440 INFO (zkCallback-1032-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> 1434447 INFO (zkCallback-1032-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> 1434525 INFO (zkCallback-1032-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> 1435934 WARN (zkCallback-1033-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1435937 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47509 47509 [junit4] 2> 1436399 INFO (Thread-10971) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47509 47509 [junit4] 2> 1436400 WARN (Thread-10971) [ ] 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> 2 /solr/overseer/queue-work [junit4] 2> 2 /solr/overseer/collection-queue-work [junit4] 2> [junit4] 2> 1436400 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testOverseerStatsReset [junit4] 2> 1436400 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315767402498-127.0.0.1:47509_solr-n_0000000001) closing [junit4] 2> 1436400 INFO (OverseerStateUpdate-94829315767402498-127.0.0.1:47509_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:47509_solr [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerStatsReset -Dtests.seed=8A16F3829FAD9E6A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=es_ES -Dtests.timezone=SystemV/PST8 -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 2.76s J2 | OverseerTest.testOverseerStatsReset <<< [junit4] > Throwable #1: java.lang.AssertionError: expected:<0> but was:<1> [junit4] > at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A:214214BE0A773D64]:0) [junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerStatsReset(OverseerTest.java:732) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1436407 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:61) [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:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1436409 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testReplay [junit4] 2> 1436409 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1436419 INFO (Thread-10972) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1436419 INFO (Thread-10972) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1436519 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer start zk server on port:55661 [junit4] 2> 1436519 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1436519 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1436551 INFO (zkCallback-1035-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@508c219 name:ZooKeeperConnection Watcher:127.0.0.1:55661/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1436551 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1436551 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1436551 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1436564 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1436574 INFO (zkCallback-1036-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@25057dfa name:ZooKeeperConnection Watcher:127.0.0.1:55661 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1436574 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1436575 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1436576 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1436599 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1436607 INFO (zkCallback-1037-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4fda80d2 name:ZooKeeperConnection Watcher:127.0.0.1:55661 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1436607 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1436607 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1436607 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1436610 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1436611 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1436612 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1436613 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1436619 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1436620 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1436622 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1436625 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1436647 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1436654 INFO (zkCallback-1038-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3a8994d9 name:ZooKeeperConnection Watcher:127.0.0.1:55661/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1436654 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1436654 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1436654 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1436655 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1436657 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1436658 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1436658 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94829315949002755-127.0.0.1:55661_solr-n_0000000000 [junit4] 2> 1436658 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:55661_solr [junit4] 2> 1436658 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1436659 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315949002755-127.0.0.1:55661_solr-n_0000000000) starting [junit4] 2> 1436660 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1436662 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1436664 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1436665 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1436667 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1436669 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1436683 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1436684 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1436685 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: workQueueSize: 2, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1436686 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_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> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1436691 INFO (OverseerCollectionConfigSetProcessor-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1436695 INFO (zkCallback-1035-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> 1436695 INFO (zkCallback-1038-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> 1436697 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: workQueueSize: 0, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1436698 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_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> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core2", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1436699 INFO (zkCallback-1038-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> 1436699 INFO (zkCallback-1035-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> 1436701 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_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> "node_name":"node1", [junit4] 2> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 2 [junit4] 2> 1436701 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_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> "shard":"s1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core3", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1436803 INFO (zkCallback-1035-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> 1436803 INFO (zkCallback-1038-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> 1436902 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:55661 55661 [junit4] 2> 1437061 INFO (Thread-10972) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:55661 55661 [junit4] 2> 1437061 WARN (Thread-10972) [ ] 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> 1437062 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testReplay [junit4] 2> 1437062 INFO (TEST-OverseerTest.testReplay-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315949002755-127.0.0.1:55661_solr-n_0000000000) closing [junit4] 2> 1437062 INFO (OverseerStateUpdate-94829315949002755-127.0.0.1:55661_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:55661_solr [junit4] 2> 1437080 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:61) [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:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1437087 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testShardAssignment [junit4] 2> 1437087 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1437097 INFO (Thread-10973) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1437097 INFO (Thread-10973) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1437197 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer start zk server on port:50005 [junit4] 2> 1437198 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1437207 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1437219 INFO (zkCallback-1040-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2d43e6f name:ZooKeeperConnection Watcher:127.0.0.1:50005 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1437219 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1437219 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1437220 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1437231 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1437237 INFO (zkCallback-1041-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@921b576 name:ZooKeeperConnection Watcher:127.0.0.1:50005 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1437237 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1437238 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1437238 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1437240 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1437254 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1437257 INFO (zkCallback-1042-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5e7c2f03 name:ZooKeeperConnection Watcher:127.0.0.1:50005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1437257 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1437258 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1437258 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1437259 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1437261 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1437262 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1437264 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1437265 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1437282 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1437282 INFO (zkCallback-1043-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3ecc1040 name:ZooKeeperConnection Watcher:127.0.0.1:50005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1437282 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1437283 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1437283 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1437284 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1437285 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1437286 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1437286 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94829315992977411-127.0.0.1:50005_solr-n_0000000000 [junit4] 2> 1437286 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50005_solr [junit4] 2> 1437287 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1437287 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315992977411-127.0.0.1:50005_solr-n_0000000000) starting [junit4] 2> 1437288 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1437290 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1437291 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1437293 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1437294 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1437295 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1437298 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1437305 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1437305 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1437306 INFO (OverseerCollectionConfigSetProcessor-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1437318 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1437320 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1437325 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1437326 INFO (zkCallback-1045-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@781f7e97 name:ZooKeeperConnection Watcher:127.0.0.1:50005/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1437332 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1437332 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1437333 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1437338 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1 [junit4] 2> 1437339 INFO (zkCallback-1042-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> 1437339 INFO (zkCallback-1043-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> 1437340 INFO (zkCallback-1045-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> 1437344 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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> 1437344 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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> 1437344 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1437345 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 1437345 INFO (zkCallback-1043-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> 1437345 INFO (zkCallback-1045-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> 1437346 INFO (zkCallback-1042-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> 1437844 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1437845 INFO (zkCallback-1043-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1437845 INFO (zkCallback-1045-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1437845 INFO (zkCallback-1042-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1437848 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard2/election/94829315992977412-127.0.0.1_core1-n_0000000000 [junit4] 2> 1437848 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1437850 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1437852 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core1"} current state version: 1 [junit4] 2> 1437854 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 1 [junit4] 2> 1437854 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1437854 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1437854 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 1437957 INFO (zkCallback-1042-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> 1437957 INFO (zkCallback-1043-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> 1437957 INFO (zkCallback-1045-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> 1438353 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1438358 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard3/election/94829315992977412-127.0.0.1_core2-n_0000000000 [junit4] 2> 1438359 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard3 [junit4] 2> 1438360 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1438362 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard3", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core2"} current state version: 2 [junit4] 2> 1438372 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 2 [junit4] 2> 1438372 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1438372 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1438372 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1438474 INFO (zkCallback-1042-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> 1438474 INFO (zkCallback-1045-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> 1438475 INFO (zkCallback-1043-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> 1438864 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1438867 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/94829315992977412-127.0.0.1_core3-n_0000000000 [junit4] 2> 1438867 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1438869 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1438871 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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://127.0.0.1/solr/", [junit4] 2> "core":"core3"} current state version: 3 [junit4] 2> 1438874 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core4", [junit4] 2> "core_node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 3 [junit4] 2> 1438874 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core4", [junit4] 2> "core_node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1438874 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1438874 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 1438976 INFO (zkCallback-1045-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> 1438976 INFO (zkCallback-1042-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> 1438980 INFO (zkCallback-1043-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> 1439376 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1439378 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard2/election/94829315992977412-127.0.0.1_core4-n_0000000001 [junit4] 2> 1439379 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Watching path /collections/collection1/leader_elect/shard2/election/94829315992977412-127.0.0.1_core1-n_0000000000 to know if I could be the leader [junit4] 2> 1439380 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core5", [junit4] 2> "core_node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 4 [junit4] 2> 1439381 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core5", [junit4] 2> "core_node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1439381 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1439381 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 1439484 INFO (zkCallback-1042-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> 1439484 INFO (zkCallback-1045-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> 1439484 INFO (zkCallback-1043-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> 1439882 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1439885 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard3/election/94829315992977412-127.0.0.1_core5-n_0000000001 [junit4] 2> 1439885 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Watching path /collections/collection1/leader_elect/shard3/election/94829315992977412-127.0.0.1_core2-n_0000000000 to know if I could be the leader [junit4] 2> 1439887 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core6", [junit4] 2> "core_node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 5 [junit4] 2> 1439895 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_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":"core6", [junit4] 2> "core_node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1439895 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1439895 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1440003 INFO (zkCallback-1045-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> 1440003 INFO (zkCallback-1042-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> 1440004 INFO (zkCallback-1043-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> 1440402 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1440405 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/94829315992977412-127.0.0.1_core6-n_0000000001 [junit4] 2> 1440405 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.LeaderElector Watching path /collections/collection1/leader_elect/shard1/election/94829315992977412-127.0.0.1_core3-n_0000000000 to know if I could be the leader [junit4] 2> 1440407 INFO (zkCallback-1043-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> 1440407 INFO (zkCallback-1045-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> 1440415 ERROR (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]-EventThread) [ ] o.a.z.ClientCnxn Error while calling watcher [junit4] 2> java.util.concurrent.RejectedExecutionException: Task org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1@43863b81 rejected from org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@684bd95[Shutting down, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 9] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:214) [junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:266) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498) [junit4] 2> 1440415 ERROR (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]-EventThread) [ ] o.a.z.ClientCnxn Error while calling watcher [junit4] 2> java.util.concurrent.RejectedExecutionException: Task org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1@37c858ad rejected from org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@684bd95[Shutting down, pool size = 2, active threads = 2, queued tasks = 0, completed tasks = 9] [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:214) [junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:266) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522) [junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498) [junit4] 2> 1440421 WARN (zkCallback-1045-thread-2) [ ] o.a.s.c.LeaderElector [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:336) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:333) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:333) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:58) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:388) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:269) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:231) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1441907 WARN (zkCallback-1045-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1441909 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:50005 50005 [junit4] 2> 1442063 INFO (Thread-10973) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:50005 50005 [junit4] 2> 1442064 WARN (Thread-10973) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 3 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 3 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 3 /solr/live_nodes [junit4] 2> 3 /solr/collections [junit4] 2> [junit4] 2> 1442064 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testShardAssignment [junit4] 2> 1442064 INFO (TEST-OverseerTest.testShardAssignment-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.Overseer Overseer (id=94829315992977411-127.0.0.1:50005_solr-n_0000000000) closing [junit4] 2> 1442067 INFO (OverseerStateUpdate-94829315992977411-127.0.0.1:50005_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:50005_solr [junit4] 2> 1442080 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadQueueItem [junit4] 2> 1442081 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1442081 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:61) [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:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1442081 INFO (Thread-10974) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1442081 INFO (Thread-10974) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1442181 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.ZkTestServer start zk server on port:57274 [junit4] 2> 1442181 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1442182 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1442184 INFO (zkCallback-1046-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6ed58d48 name:ZooKeeperConnection Watcher:127.0.0.1:57274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1442184 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1442184 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1442185 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1442186 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1442186 INFO (zkCallback-1047-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@17f1ff27 name:ZooKeeperConnection Watcher:127.0.0.1:57274 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1442186 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1442187 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1442187 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1442188 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1442189 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1442190 INFO (zkCallback-1048-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@b426080 name:ZooKeeperConnection Watcher:127.0.0.1:57274/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1442190 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1442190 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1442190 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1442191 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1442193 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1442194 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1442195 INFO (TEST-OverseerTest.testBadQueueItem-seed#[8A16F3829FAD9E6A]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1442196 INFO (TEST-OverseerTes [...truncated too long message...] itiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR-seed#[8A16F3829FAD9E6A]) [n:127.0.0.1:41702_yd_%2Fa c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59544 59544 [junit4] 2> 3148853 INFO (Thread-61657) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59544 59544 [junit4] 2> 3148854 WARN (Thread-61657) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 6 /solr/aliases.json [junit4] 2> 5 /solr/security.json [junit4] 2> 5 /solr/configs/conf1 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 6 /solr/clusterstate.json [junit4] 2> 3 /solr/overseer_elect/election/94829425329569796-127.0.0.1:54782_yd_%2Fa-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 6 /solr/collections [junit4] 2> 4 /solr/live_nodes [junit4] 2> 3 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/overseer/queue [junit4] 2> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=LeaderInitiatedRecoveryOnShardRestartTest -Dtests.method=testRestartWithAllInLIR -Dtests.seed=8A16F3829FAD9E6A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=th -Dtests.timezone=JST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] ERROR 43.4s J2 | LeaderInitiatedRecoveryOnShardRestartTest.testRestartWithAllInLIR <<< [junit4] > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=72535, name=coreZkRegister-5993-thread-1, state=RUNNABLE, group=TGRP-LeaderInitiatedRecoveryOnShardRestartTest] [junit4] > at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A:549C9DFFA40FFC99]:0) [junit4] > Caused by: java.lang.AssertionError [junit4] > at __randomizedtesting.SeedInfo.seed([8A16F3829FAD9E6A]:0) [junit4] > at org.apache.solr.cloud.ZkController.updateLeaderInitiatedRecoveryState(ZkController.java:2126) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:451) [junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:197) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:346) [junit4] > at org.apache.solr.cloud.ZkController.joinElection(ZkController.java:1113) [junit4] > at org.apache.solr.cloud.ZkController.register(ZkController.java:926) [junit4] > at org.apache.solr.cloud.ZkController.register(ZkController.java:881) [junit4] > at org.apache.solr.core.ZkContainer$2.run(ZkContainer.java:183) [junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:231) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 3148856 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartTest-seed#[8A16F3829FAD9E6A]-worker) [n:127.0.0.1:41702_yd_%2Fa c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> Nov 08, 2015 11:30:41 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=6, maxDocsPerChunk=402, blockSize=449), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=6, blockSize=449)), sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=th, timezone=JST [junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_66 (64-bit)/cpus=4,threads=1,free=247071752,total=526909440 [junit4] 2> NOTE: All tests run in this JVM: [UnloadDistributedZkTest, TestSolrIndexConfig, ConnectionManagerTest, ScriptEngineTest, BadIndexSchemaTest, UpdateParamsTest, DeleteReplicaTest, TestDownShardTolerantSearch, SampleTest, AutoCommitTest, TestSort, FieldMutatingUpdateProcessorTest, TestDistributedStatsComponentCardinality, SimpleCollectionCreateDeleteTest, TestDistributedMissingSort, TestRandomRequestDistribution, TestPHPSerializedResponseWriter, MultiThreadedOCPTest, BigEndianAscendingWordDeserializerTest, PluginInfoTest, TestExtendedDismaxParser, ChangedSchemaMergeTest, UUIDUpdateProcessorFallbackTest, LeaderElectionTest, TestPerFieldSimilarity, OverseerStatusTest, CdcrVersionReplicationTest, HdfsThreadLeakTest, TestSolrConfigHandlerConcurrent, TestMiniSolrCloudCluster, TestJmxMonitoredMap, TestSchemaNameResource, TestStressRecovery, TestWriterPerf, TestScoreJoinQPNoScore, InfoHandlerTest, TestExceedMaxTermLength, AliasIntegrationTest, RemoteQueryErrorTest, SearchHandlerTest, TestReloadAndDeleteDocs, ZkStateWriterTest, HdfsWriteToMultipleCollectionsTest, HdfsChaosMonkeyNothingIsSafeTest, SimpleFacetsTest, LeaderFailoverAfterPartitionTest, HdfsBasicDistributedZk2Test, DistributedFacetPivotLongTailTest, TestSuggestSpellingConverter, TestConfigSetsAPI, TestDistribIDF, TestSchemaResource, BlockDirectoryTest, TestMiniSolrCloudClusterSSL, ActionThrottleTest, HdfsUnloadDistributedZkTest, TestElisionMultitermQuery, SolrCoreCheckLockOnStartupTest, CircularListTest, OverriddenZkACLAndCredentialsProvidersTest, TestSolrDynamicMBean, TestReload, TestExpandComponent, OverseerTest, TestRestManager, DistributedVersionInfoTest, RecoveryAfterSoftCommitTest, XmlUpdateRequestHandlerTest, ResponseHeaderTest, DateMathParserTest, DirectSolrConnectionTest, PrimitiveFieldTypeTest, TestAuthorizationFramework, TestStandardQParsers, TestFieldCollectionResource, SharedFSAutoReplicaFailoverUtilsTest, StatsComponentTest, BadCopyFieldTest, OverseerTaskQueueTest, TestRecovery, OverseerCollectionConfigSetProcessorTest, TestBulkSchemaConcurrent, TestConfigSetsAPIZkFailure, CurrencyFieldXmlFileTest, TestSerializedLuceneMatchVersion, TestRandomMergePolicy, TestXIncludeConfig, OverseerRolesTest, DistribJoinFromCollectionTest, BasicDistributedZkTest, BasicDistributedZk2Test, RecoveryZkTest, FullSolrCloudDistribCmdsTest, TestRandomFaceting, ZkSolrClientTest, TestZkChroot, TestDistributedSearch, ShowFileRequestHandlerTest, SimplePostToolTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTest, TestTrie, SuggesterWFSTTest, NoCacheHeaderTest, TestPseudoReturnFields, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, StatelessScriptUpdateProcessorFactoryTest, XsltUpdateRequestHandlerTest, DebugComponentTest, DisMaxRequestHandlerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TestOmitPositions, TermsComponentTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, RegexBoostProcessorTest, TestJmxIntegration, UpdateRequestProcessorFactoryTest, JSONWriterTest, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, TestBinaryResponseWriter, BadComponentTest, TestSearchPerf, NumericFieldsTest, TestConfig, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, SynonymTokenizerTest, EchoParamsTest, TestDFRSimilarityFactory, TestFastWriter, OpenExchangeRatesOrgProviderTest, TestSystemIdResolver, SpellingQueryConverterTest, TestSolrJ, TestUtils, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, TestTolerantSearch, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, AssignTest, AsyncMigrateRouteKeyTest, CdcrReplicationHandlerTest, CloudExitableDirectoryReaderTest, ConcurrentDeleteAndCreateCollectionTest, DeleteLastCustomShardedReplicaTest, LeaderInitiatedRecoveryOnCommitTest, LeaderInitiatedRecoveryOnShardRestartTest] [junit4] Completed [429/555] on J2 in 44.02s, 1 test, 1 error <<< FAILURES! [...truncated 421 lines...] BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:782: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:719: 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:516: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1432: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:987: There were test failures: 555 suites (8 ignored), 2200 tests, 2 errors, 1 failure, 32 ignored (18 assumptions) [seed: 8A16F3829FAD9E6A] Total time: 194 minutes 40 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