Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.x/825/
1 tests failed. FAILED: org.apache.solr.core.snapshots.TestSolrCloudSnapshots.testSnapshots Error Message: Error from server at http://127.0.0.1:52439/solr: Could not fully remove collection: SolrCloudSnapshots Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:52439/solr: Could not fully remove collection: SolrCloudSnapshots at __randomizedtesting.SeedInfo.seed([D7D8ADCAF5492F4F:E194295580102D00]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:610) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:435) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:387) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1364) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1115) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1054) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:177) at org.apache.solr.core.snapshots.TestSolrCloudSnapshots.testSnapshots(TestSolrCloudSnapshots.java:266) 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:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 12932 lines...] [junit4] Suite: org.apache.solr.core.snapshots.TestSolrCloudSnapshots [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/init-core-data-001 [junit4] 2> 2441116 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields [junit4] 2> 2441117 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) [junit4] 2> 2441120 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001 [junit4] 2> 2441122 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2441141 INFO (Thread-4807) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2441141 INFO (Thread-4807) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2441241 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:49029 [junit4] 2> 2441330 INFO (jetty-launcher-4002-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2441353 INFO (jetty-launcher-4002-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2441358 INFO (jetty-launcher-4002-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2441392 INFO (jetty-launcher-4002-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2441571 INFO (jetty-launcher-4002-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@30a6211a{/solr,null,AVAILABLE} [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5336b71{HTTP/1.1,[http/1.1]}{127.0.0.1:46958} [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.e.j.s.Server Started @2448447ms [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46958} [junit4] 2> 2441572 ERROR (jetty-launcher-4002-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.0 [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2441572 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-06T02:22:42.176Z [junit4] 2> 2441758 INFO (jetty-launcher-4002-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d0bb4ce{/solr,null,AVAILABLE} [junit4] 2> 2441759 INFO (jetty-launcher-4002-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7f5b8411{HTTP/1.1,[http/1.1]}{127.0.0.1:52439} [junit4] 2> 2441759 INFO (jetty-launcher-4002-thread-1) [ ] o.e.j.s.Server Started @2448634ms [junit4] 2> 2441759 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52439} [junit4] 2> 2441760 ERROR (jetty-launcher-4002-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2441760 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.0 [junit4] 2> 2441760 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2441760 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2441760 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-06T02:22:42.364Z [junit4] 2> 2441775 INFO (jetty-launcher-4002-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@358c33b6{/solr,null,AVAILABLE} [junit4] 2> 2441775 INFO (jetty-launcher-4002-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@34782381{HTTP/1.1,[http/1.1]}{127.0.0.1:34557} [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.e.j.s.Server Started @2448651ms [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34557} [junit4] 2> 2441776 ERROR (jetty-launcher-4002-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.0 [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2441776 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-06T02:22:42.380Z [junit4] 2> 2441785 INFO (jetty-launcher-4002-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@372608fc{/solr,null,AVAILABLE} [junit4] 2> 2441785 INFO (jetty-launcher-4002-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@62cf6565{HTTP/1.1,[http/1.1]}{127.0.0.1:49271} [junit4] 2> 2441785 INFO (jetty-launcher-4002-thread-3) [ ] o.e.j.s.Server Started @2448660ms [junit4] 2> 2441785 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=49271} [junit4] 2> 2441785 ERROR (jetty-launcher-4002-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2441785 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.0 [junit4] 2> 2441786 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2441786 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2441786 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-04-06T02:22:42.390Z [junit4] 2> 2441815 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2441830 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2441870 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2441934 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2441937 INFO (jetty-launcher-4002-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49029/solr [junit4] 2> 2441946 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2441953 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2441947 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2441974 INFO (jetty-launcher-4002-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49029/solr [junit4] 2> 2441990 INFO (jetty-launcher-4002-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49029/solr [junit4] 2> 2441995 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 2442039 INFO (jetty-launcher-4002-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49029/solr [junit4] 2> 2442105 INFO (jetty-launcher-4002-thread-4) [n:127.0.0.1:34557_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2442112 INFO (jetty-launcher-4002-thread-4) [n:127.0.0.1:34557_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34557_solr [junit4] 2> 2442113 INFO (jetty-launcher-4002-thread-4) [n:127.0.0.1:34557_solr ] o.a.s.c.Overseer Overseer (id=97743363228368903-127.0.0.1:34557_solr-n_0000000000) starting [junit4] 2> 2442125 INFO (jetty-launcher-4002-thread-4) [n:127.0.0.1:34557_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34557_solr [junit4] 2> 2442131 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2442137 INFO (jetty-launcher-4002-thread-2) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2442137 INFO (jetty-launcher-4002-thread-3) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2442141 INFO (jetty-launcher-4002-thread-2) [n:127.0.0.1:46958_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2442141 INFO (jetty-launcher-4002-thread-3) [n:127.0.0.1:49271_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2442148 INFO (jetty-launcher-4002-thread-3) [n:127.0.0.1:49271_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49271_solr [junit4] 2> 2442148 INFO (jetty-launcher-4002-thread-2) [n:127.0.0.1:46958_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46958_solr [junit4] 2> 2442160 INFO (jetty-launcher-4002-thread-1) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 2442163 INFO (jetty-launcher-4002-thread-1) [n:127.0.0.1:52439_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2442170 INFO (jetty-launcher-4002-thread-1) [n:127.0.0.1:52439_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52439_solr [junit4] 2> 2442198 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2442198 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2442199 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2442202 INFO (zkCallback-4017-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2442450 INFO (jetty-launcher-4002-thread-2) [n:127.0.0.1:46958_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node2/. [junit4] 2> 2442459 INFO (jetty-launcher-4002-thread-3) [n:127.0.0.1:49271_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node3/. [junit4] 2> 2442482 INFO (jetty-launcher-4002-thread-4) [n:127.0.0.1:34557_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node4/. [junit4] 2> 2442658 INFO (jetty-launcher-4002-thread-1) [n:127.0.0.1:52439_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node1/. [junit4] 2> 2448545 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2448546 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49029/solr ready [junit4] 2> 2448585 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSnapshots [junit4] 2> 2448587 INFO (qtp849585627-19586) [n:127.0.0.1:52439_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf1&name=SolrCloudSnapshots&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2448590 INFO (OverseerThreadFactory-7325-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateCollectionCmd Create collection SolrCloudSnapshots [junit4] 2> 2448710 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard2_replica1&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard2&wt=javabin&version=2 [junit4] 2> 2448710 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2448712 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard2_replica2&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard2&wt=javabin&version=2 [junit4] 2> 2448712 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2448718 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard1_replica1&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard1&wt=javabin&version=2 [junit4] 2> 2448718 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2448718 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard1_replica2&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard1&wt=javabin&version=2 [junit4] 2> 2448719 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2448824 INFO (zkCallback-4017-thread-3-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2448824 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2448824 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2448824 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2449760 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 2449766 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 2449770 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 2449777 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0 [junit4] 2> 2449801 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard2_replica2] Schema name=minimal [junit4] 2> 2449816 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard2_replica1] Schema name=minimal [junit4] 2> 2449825 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2449825 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'SolrCloudSnapshots_shard2_replica2' using configuration from collection SolrCloudSnapshots, trusted=true [junit4] 2> 2449825 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2449825 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard2_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node4/SolrCloudSnapshots_shard2_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node4/./SolrCloudSnapshots_shard2_replica2/data/] [junit4] 2> 2449826 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2449827 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'SolrCloudSnapshots_shard2_replica1' using configuration from collection SolrCloudSnapshots, trusted=true [junit4] 2> 2449827 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2449827 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node3/SolrCloudSnapshots_shard2_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/] [junit4] 2> 2449832 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard1_replica2] Schema name=minimal [junit4] 2> 2449835 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2449835 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'SolrCloudSnapshots_shard1_replica2' using configuration from collection SolrCloudSnapshots, trusted=true [junit4] 2> 2449835 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard1_replica1] Schema name=minimal [junit4] 2> 2449840 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2449840 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'SolrCloudSnapshots_shard1_replica1' using configuration from collection SolrCloudSnapshots, trusted=true [junit4] 2> 2449841 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2449841 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node2/SolrCloudSnapshots_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node2/./SolrCloudSnapshots_shard1_replica1/data/] [junit4] 2> 2449843 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2449843 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node1/SolrCloudSnapshots_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node1/./SolrCloudSnapshots_shard1_replica2/data/] [junit4] 2> 2450015 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2450015 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2450016 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2450016 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2450019 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@6f962651[SolrCloudSnapshots_shard1_replica2] main] [junit4] 2> 2450020 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2450020 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2450021 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2450021 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2450022 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2450023 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2450023 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2450023 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563893820950577152 [junit4] 2> 2450024 INFO (searcherExecutor-7337-thread-1-processing-n:127.0.0.1:52439_solr x:SolrCloudSnapshots_shard1_replica2 s:shard1 c:SolrCloudSnapshots) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica2] Registered new searcher Searcher@6f962651[SolrCloudSnapshots_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2450030 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms [junit4] 2> 2450035 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@761de1e[SolrCloudSnapshots_shard2_replica1] main] [junit4] 2> 2450041 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2450042 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2450042 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2450043 INFO (searcherExecutor-7335-thread-1-processing-n:127.0.0.1:49271_solr x:SolrCloudSnapshots_shard2_replica1 s:shard2 c:SolrCloudSnapshots) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica1] Registered new searcher Searcher@761de1e[SolrCloudSnapshots_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2450043 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563893820971548672 [junit4] 2> 2450060 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms [junit4] 2> 2450067 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2450067 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2450068 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2450068 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2450070 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@2320d19[SolrCloudSnapshots_shard2_replica2] main] [junit4] 2> 2450070 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2450070 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2450071 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2450071 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2450073 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@31d51acd[SolrCloudSnapshots_shard1_replica1] main] [junit4] 2> 2450074 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2450074 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2450074 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2450074 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563893821004054528 [junit4] 2> 2450076 INFO (searcherExecutor-7334-thread-1-processing-n:127.0.0.1:34557_solr x:SolrCloudSnapshots_shard2_replica2 s:shard2 c:SolrCloudSnapshots) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica2] Registered new searcher Searcher@2320d19[SolrCloudSnapshots_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2450077 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2450077 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2450077 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2450078 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1563893821008248832 [junit4] 2> 2450080 INFO (searcherExecutor-7336-thread-1-processing-n:127.0.0.1:46958_solr x:SolrCloudSnapshots_shard1_replica1 s:shard1 c:SolrCloudSnapshots) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1] Registered new searcher Searcher@31d51acd[SolrCloudSnapshots_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2450163 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450163 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450163 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450164 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450531 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2450531 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2450531 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/ [junit4] 2> 2450532 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=SolrCloudSnapshots_shard1_replica2 url=http://127.0.0.1:52439/solr START replicas=[http://127.0.0.1:46958/solr/SolrCloudSnapshots_shard1_replica1/] nUpdates=100 [junit4] 2> 2450538 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=SolrCloudSnapshots_shard1_replica2 url=http://127.0.0.1:52439/solr DONE. We have no versions. sync failed. [junit4] 2> 2450541 INFO (qtp1553780907-19572) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2450541 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 2450541 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway [junit4] 2> 2450541 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2450551 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/ shard1 [junit4] 2> 2450561 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2450561 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2450561 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/ [junit4] 2> 2450561 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=SolrCloudSnapshots_shard2_replica1 url=http://127.0.0.1:49271/solr START replicas=[http://127.0.0.1:34557/solr/SolrCloudSnapshots_shard2_replica2/] nUpdates=100 [junit4] 2> 2450565 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=SolrCloudSnapshots_shard2_replica1 url=http://127.0.0.1:49271/solr DONE. We have no versions. sync failed. [junit4] 2> 2450568 INFO (qtp2054981890-19594) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2450572 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 2450572 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway [junit4] 2> 2450572 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2450581 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/ shard2 [junit4] 2> 2450684 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450684 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450684 INFO (zkCallback-4017-thread-3-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450684 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450702 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2450704 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard1_replica2&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard1&wt=javabin&version=2} status=0 QTime=1986 [junit4] 2> 2450732 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2450734 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard2_replica1&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard2&wt=javabin&version=2} status=0 QTime=2024 [junit4] 2> 2450836 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450836 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450837 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2450837 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2451082 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard2_replica2&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard2&wt=javabin&version=2} status=0 QTime=2370 [junit4] 2> 2451085 INFO (qtp1553780907-19576) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=SolrCloudSnapshots_shard1_replica1&action=CREATE&numShards=2&collection=SolrCloudSnapshots&shard=shard1&wt=javabin&version=2} status=0 QTime=2367 [junit4] 2> 2451087 INFO (qtp849585627-19586) [n:127.0.0.1:52439_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 2451193 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2451193 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2451193 INFO (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2451193 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2452087 INFO (qtp849585627-19586) [n:127.0.0.1:52439_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf1&name=SolrCloudSnapshots&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3500 [junit4] 2> 2452106 INFO (qtp1553780907-19572) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1563893823120080896&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1563893823120080896)} 0 2 [junit4] 2> 2452111 INFO (qtp2054981890-19594) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1563893823129518080&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1563893823129518080)} 0 3 [junit4] 2> 2452111 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1563893823129518080)} 0 10 [junit4] 2> 2452111 INFO (qtp849585627-19587) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1563893823120080896)} 0 20 [junit4] 2> 2452112 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.a.s.h.BackupRestoreUtils Indexing 94 test docs [junit4] 2> 2452120 INFO (qtp2054981890-19593) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2}{add=[2 (1563893823145246720), 3 (1563893823145246721), 5 (1563893823146295296), 6 (1563893823146295297), 7 (1563893823146295298), 9 (1563893823146295299), 17 (1563893823146295300), 18 (1563893823146295301), 19 (1563893823146295302), 21 (1563893823146295303), ... (41 adds)]} 0 2 [junit4] 2> 2452120 INFO (qtp1755873987-19607) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1563893823145246720), 3 (1563893823145246721), 5 (1563893823146295296), 6 (1563893823146295297), 7 (1563893823146295298), 9 (1563893823146295299), 17 (1563893823146295300), 18 (1563893823146295301), 19 (1563893823146295302), 21 (1563893823146295303), ... (41 adds)]} 0 4 [junit4] 2> 2452128 INFO (qtp1553780907-19570) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{add=[0 (1563893823149441024), 1 (1563893823150489600), 4 (1563893823150489601), 8 (1563893823150489602), 10 (1563893823150489603), 11 (1563893823150489604), 12 (1563893823150489605), 13 (1563893823150489606), 14 (1563893823150489607), 15 (1563893823150489608), ... (53 adds)]} 0 2 [junit4] 2> 2452128 INFO (qtp849585627-19583) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1563893823149441024), 1 (1563893823150489600), 4 (1563893823150489601), 8 (1563893823150489602), 10 (1563893823150489603), 11 (1563893823150489604), 12 (1563893823150489605), 13 (1563893823150489606), 14 (1563893823150489607), 15 (1563893823150489608), ... (53 adds)]} 0 7 [junit4] 2> 2452131 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2452131 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6f1c2618 [junit4] 2> 2452136 INFO (qtp1553780907-19574) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2452137 INFO (qtp1755873987-19610) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2452137 INFO (qtp1553780907-19574) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@718c5187 [junit4] 2> 2452137 INFO (qtp1755873987-19610) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7833e7fd [junit4] 2> 2452142 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2452142 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7a8adec1 [junit4] 2> 2452174 INFO (qtp1755873987-19610) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3534d7b7[SolrCloudSnapshots_shard2_replica1] main] [junit4] 2> 2452174 INFO (qtp1755873987-19610) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2452174 INFO (searcherExecutor-7335-thread-1-processing-n:127.0.0.1:49271_solr x:SolrCloudSnapshots_shard2_replica1 s:shard2 c:SolrCloudSnapshots r:core_node1) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica1] Registered new searcher Searcher@3534d7b7[SolrCloudSnapshots_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.0):C41)))} [junit4] 2> 2452174 INFO (qtp1755873987-19610) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 38 [junit4] 2> 2452183 INFO (qtp1553780907-19574) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@422db539[SolrCloudSnapshots_shard1_replica1] main] [junit4] 2> 2452183 INFO (searcherExecutor-7336-thread-1-processing-n:127.0.0.1:46958_solr x:SolrCloudSnapshots_shard1_replica1 s:shard1 c:SolrCloudSnapshots r:core_node3) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1] Registered new searcher Searcher@422db539[SolrCloudSnapshots_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.0):C53)))} [junit4] 2> 2452183 INFO (qtp1553780907-19574) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2452184 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@21306ed0[SolrCloudSnapshots_shard2_replica2] main] [junit4] 2> 2452184 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2452184 INFO (searcherExecutor-7334-thread-1-processing-n:127.0.0.1:34557_solr x:SolrCloudSnapshots_shard2_replica2 s:shard2 c:SolrCloudSnapshots r:core_node2) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica2] Registered new searcher Searcher@21306ed0[SolrCloudSnapshots_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.0):C41)))} [junit4] 2> 2452184 INFO (qtp1553780907-19574) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 47 [junit4] 2> 2452184 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 42 [junit4] 2> 2452185 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3bf7ae13[SolrCloudSnapshots_shard1_replica2] main] [junit4] 2> 2452185 INFO (searcherExecutor-7337-thread-1-processing-n:127.0.0.1:52439_solr x:SolrCloudSnapshots_shard1_replica2 s:shard1 c:SolrCloudSnapshots r:core_node4) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica2] Registered new searcher Searcher@3bf7ae13[SolrCloudSnapshots_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.0):C53)))} [junit4] 2> 2452185 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2452185 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 54 [junit4] 2> 2452185 INFO (qtp849585627-19589) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={_stateVer_=SolrCloudSnapshots:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 55 [junit4] 2> 2452189 INFO (qtp849585627-19586) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.S.Request [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=SolrCloudSnapshots:5&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/|http://127.0.0.1:46958/solr/SolrCloudSnapshots_shard1_replica1/&rows=10&version=2&q=*:*&NOW=1491445372790&isShard=true&wt=javabin} hits=53 status=0 QTime=0 [junit4] 2> 2452189 INFO (qtp1755873987-19608) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=SolrCloudSnapshots:5&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/|http://127.0.0.1:34557/solr/SolrCloudSnapshots_shard2_replica2/&rows=10&version=2&q=*:*&NOW=1491445372790&isShard=true&wt=javabin} hits=41 status=0 QTime=0 [junit4] 2> 2452191 INFO (qtp1755873987-19611) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=SolrCloudSnapshots:5&shards.purpose=64&NOW=1491445372790&ids=2,3,5,17,6,18,7,19,9,21&isShard=true&shard.url=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/|http://127.0.0.1:34557/solr/SolrCloudSnapshots_shard2_replica2/&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2452191 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/select params={q=*:*&_stateVer_=SolrCloudSnapshots:5&wt=javabin&version=2} hits=94 status=0 QTime=5 [junit4] 2> 2452193 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5336b71{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 2452194 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=692558933 [junit4] 2> 2452196 INFO (coreCloseExecutor-7354-thread-1) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@7b4b7a3a [junit4] 2> 2452204 INFO (coreCloseExecutor-7354-thread-1) [n:127.0.0.1:46958_solr c:SolrCloudSnapshots s:shard1 r:core_node3 x:SolrCloudSnapshots_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.SolrCloudSnapshots.shard1.replica1 [junit4] 2> 2452206 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 2452206 INFO (zkCallback-4032-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 2452206 INFO (zkCallback-4022-thread-1-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 2452206 INFO (zkCallback-4017-thread-3-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 2452305 INFO (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [3]) [junit4] 2> 2452305 INFO (zkCallback-4017-thread-3-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [3]) [junit4] 2> 2452305 INFO (zkCallback-4022-thread-2-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/SolrCloudSnapshots/state.json] for collection [SolrCloudSnapshots] has occurred - updating... (live nodes size: [3]) [junit4] 2> 2452592 INFO (OverseerCollectionConfigSetProcessor-97743363228368903-127.0.0.1:34557_solr-n_0000000000) [n:127.0.0.1:34557_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 2453705 WARN (zkCallback-4024-thread-1-processing-n:127.0.0.1:46958_solr) [n:127.0.0.1:46958_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2453706 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 2453707 INFO (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[D7D8ADCAF5492F4F]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@30a6211a{/solr,null,UNAVAILABLE} [junit4] 2> 2458712 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createsnapshot with params name=SolrCloudSnapshots&action=CREATESNAPSHOT&collection=SolrCloudSnapshots&commitName=stf&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2458725 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Creating a snapshot for collection=SolrCloudSnapshots with commitName=stf [junit4] 2> 2458729 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Created a ZK path to store snapshot information for collection=SolrCloudSnapshots with commitName=stf [junit4] 2> 2458729 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Replica SolrCloudSnapshots_shard1_replica1 is not active. Hence not sending the createsnapshot request [junit4] 2> 2458745 INFO (qtp849585627-19587) [n:127.0.0.1:52439_solr ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named stf for core SolrCloudSnapshots_shard1_replica2 associated with index commit with generation 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node1/./SolrCloudSnapshots_shard1_replica2/data/index/ [junit4] 2> 2458749 INFO (qtp849585627-19587) [n:127.0.0.1:52439_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard1_replica2&qt=/admin/cores&name=shard1&action=CREATESNAPSHOT&commitName=stf&wt=javabin&version=2} status=0 QTime=4 [junit4] 2> 2458755 INFO (qtp1755873987-19605) [n:127.0.0.1:49271_solr ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named stf for core SolrCloudSnapshots_shard2_replica1 associated with index commit with generation 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/index/ [junit4] 2> 2458757 INFO (qtp1755873987-19605) [n:127.0.0.1:49271_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard2_replica1&qt=/admin/cores&name=shard2&action=CREATESNAPSHOT&commitName=stf&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 2458761 INFO (qtp2054981890-19597) [n:127.0.0.1:34557_solr ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named stf for core SolrCloudSnapshots_shard2_replica2 associated with index commit with generation 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node4/./SolrCloudSnapshots_shard2_replica2/data/index/ [junit4] 2> 2458763 INFO (qtp2054981890-19597) [n:127.0.0.1:34557_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard2_replica2&qt=/admin/cores&name=shard2&action=CREATESNAPSHOT&commitName=stf&wt=javabin&version=2} status=0 QTime=5 [junit4] 2> 2458765 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName stf is created successfully for core SolrCloudSnapshots_shard1_replica2 [junit4] 2> 2458765 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName stf is created successfully for core SolrCloudSnapshots_shard2_replica1 [junit4] 2> 2458765 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName stf is created successfully for core SolrCloudSnapshots_shard2_replica2 [junit4] 2> 2458766 INFO (OverseerThreadFactory-7325-thread-2-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.CreateSnapshotCmd Saved following snapshot information for collection=SolrCloudSnapshots with commitName=stf in Zookeeper : {name=stf,status=Successful,creationDate=1491445379328,replicas={SolrCloudSnapshots_shard1_replica2={core=SolrCloudSnapshots_shard1_replica2,indexDirPath=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node1/./SolrCloudSnapshots_shard1_replica2/data/index/,generation=2,shard_id=shard1,leader=true,files=[_0_BlockTreeOrds_0.pos, _0.si, _0_FSTOrd50_0.doc, _0_FSTOrd50_0.pos, segments_2, _0.nvd, _0.fdx, _0_BlockTreeOrds_0.tio, _0_BlockTreeOrds_0.doc, _0.fdt, _0_BlockTreeOrds_0.tipo, _0_FSTOrd50_0.tix, _0_FSTOrd50_0.tbk, _0.nvm, _0.fnm]},SolrCloudSnapshots_shard2_replica1={core=SolrCloudSnapshots_shard2_replica1,indexDirPath=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/index/,generation=2,shard_id=shard2,leader=true,files=[_0_BlockTreeOrds_0.pos, _0.si, _0_FSTOrd50_0.doc, _0_FSTOrd50_0.pos, segments_2, _0.nvd, _0.fdx, _0_BlockTreeOrds_0.tio, _0_BlockTreeOrds_0.doc, _0.fdt, _0_BlockTreeOrds_0.tipo, _0_FSTOrd50_0.tix, _0_FSTOrd50_0.tbk, _0.nvm, _0.fnm]},SolrCloudSnapshots_shard2_replica2={core=SolrCloudSnapshots_shard2_replica2,indexDirPath=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001/tempDir-001/node4/./SolrCloudSnapshots_shard2_replica2/data/index/,generation=2,shard_id=shard2,leader=false,files=[_0_BlockTreeOrds_0.pos, _0.si, _0_FSTOrd50_0.doc, _0_FSTOrd50_0.pos, segments_2, _0.nvd, _0.fdx, _0_BlockTreeOrds_0.tio, _0_BlockTreeOrds_0.doc, _0.fdt, _0_BlockTreeOrds_0.tipo, _0_FSTOrd50_0.tix, _0_FSTOrd50_0.tbk, _0.nvm, _0.fnm]}}} [junit4] 2> 2458768 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=SolrCloudSnapshots&action=CREATESNAPSHOT&collection=SolrCloudSnapshots&commitName=stf&wt=javabin&version=2} status=0 QTime=56 [junit4] 2> 2458771 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :listsnapshots with params name=SolrCloudSnapshots&action=LISTSNAPSHOTS&collection=SolrCloudSnapshots&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2458772 INFO (qtp849585627-19584) [n:127.0.0.1:52439_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=SolrCloudSnapshots&action=LISTSNAPSHOTS&collection=SolrCloudSnapshots&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 2458779 INFO (qtp1755873987-19609) [n:127.0.0.1:49271_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard2_replica1&action=LISTSNAPSHOTS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2458787 INFO (qtp2054981890-19593) [n:127.0.0.1:34557_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard2_replica2&action=LISTSNAPSHOTS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2458788 INFO (qtp849585627-19583) [n:127.0.0.1:52439_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=SolrCloudSnapshots_shard1_replica2&action=LISTSNAPSHOTS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2458795 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@12a57611[SolrCloudSnapshots_shard1_replica2] realtime] [junit4] 2> 2458797 INFO (qtp1755873987-19609) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@24dba320[SolrCloudSnapshots_shard2_replica1] realtime] [junit4] 2> 2458810 INFO (qtp2054981890-19594) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5c9492[SolrCloudSnapshots_shard2_replica2] realtime] [junit4] 2> 2458810 INFO (qtp2054981890-19594) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1563893830148685824&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1563893830148685824)} 0 2 [junit4] 2> 2458810 INFO (qtp1755873987-19609) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:52439/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1563893830148685824)} 0 15 [junit4] 2> 2458811 INFO (qtp849585627-19588) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1563893830146588672)} 0 17 [junit4] 2> 2458814 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2458814 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6f1c2618 [junit4] 2> 2458835 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2458835 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7833e7fd [junit4] 2> 2458854 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@576fd998[SolrCloudSnapshots_shard2_replica1] main] [junit4] 2> 2458855 INFO (searcherExecutor-7335-thread-1-processing-n:127.0.0.1:49271_solr x:SolrCloudSnapshots_shard2_replica1 s:shard2 c:SolrCloudSnapshots r:core_node1) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica1] Registered new searcher Searcher@576fd998[SolrCloudSnapshots_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2458855 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2458855 INFO (qtp1755873987-19571) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 20 [junit4] 2> 2458868 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@35b1a90b[SolrCloudSnapshots_shard1_replica2] main] [junit4] 2> 2458869 INFO (searcherExecutor-7337-thread-1-processing-n:127.0.0.1:52439_solr x:SolrCloudSnapshots_shard1_replica2 s:shard1 c:SolrCloudSnapshots r:core_node4) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica2] Registered new searcher Searcher@35b1a90b[SolrCloudSnapshots_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2458869 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2458869 INFO (qtp849585627-19590) [n:127.0.0.1:52439_solr c:SolrCloudSnapshots s:shard1 r:core_node4 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 55 [junit4] 2> 2458870 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2458870 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7a8adec1 [junit4] 2> 2458874 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@a16b7d8[SolrCloudSnapshots_shard2_replica2] main] [junit4] 2> 2458875 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2458875 INFO (searcherExecutor-7334-thread-1-processing-n:127.0.0.1:34557_solr x:SolrCloudSnapshots_shard2_replica2 s:shard2 c:SolrCloudSnapshots r:core_node2) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica2] Registered new searcher Searcher@a16b7d8[SolrCloudSnapshots_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2458875 INFO (qtp2054981890-19600) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:49271/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5 [junit4] 2> 2458876 INFO (qtp1755873987-19608) [n:127.0.0.1:49271_solr c:SolrCloudSnapshots s:shard2 r:core_node1 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1] webapp=/solr path=/update params={_stateVer_=SolrCloudSnapshots:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 63 [junit4] 2> 2458880 INFO (qtp2054981890-19596) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots s:shard2 r:core_node2 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.S.Requ [...truncated too long message...] StateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2500072 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2500072 WARN (zkCallback-4025-thread-1-processing-n:127.0.0.1:52439_solr) [n:127.0.0.1:52439_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2500072 INFO (coreCloseExecutor-7379-thread-1) [n:127.0.0.1:34557_solr c:SolrCloudSnapshots_restored s:shard1 r:core_node4 x:SolrCloudSnapshots_restored_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.SolrCloudSnapshots_restored.shard1.replica1 [junit4] 2> 2500073 INFO (jetty-closer-4003-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 2500073 INFO (jetty-closer-4003-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@d0bb4ce{/solr,null,UNAVAILABLE} [junit4] 2> 2500081 INFO (jetty-closer-4003-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97743363228368903-127.0.0.1:34557_solr-n_0000000000) closing [junit4] 2> 2500082 INFO (OverseerStateUpdate-97743363228368903-127.0.0.1:34557_solr-n_0000000000) [n:127.0.0.1:34557_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:34557_solr [junit4] 2> 2500093 WARN (zkCallback-4022-thread-2-processing-n:127.0.0.1:49271_solr) [n:127.0.0.1:49271_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2500093 INFO (jetty-closer-4003-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 2500093 INFO (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 2500095 INFO (jetty-closer-4003-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@372608fc{/solr,null,UNAVAILABLE} [junit4] 2> 2501600 WARN (zkCallback-4017-thread-1-processing-n:127.0.0.1:34557_solr) [n:127.0.0.1:34557_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2501600 INFO (jetty-closer-4003-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 2501601 INFO (jetty-closer-4003-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@358c33b6{/solr,null,UNAVAILABLE} [junit4] 2> 2501602 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49029 49029 [junit4] 2> 2501704 INFO (Thread-4807) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49029 49029 [junit4] 2> 2501705 WARN (Thread-4807) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 5 /solr/clusterprops.json [junit4] 2> 5 /solr/aliases.json [junit4] 2> 4 /solr/security.json [junit4] 2> 4 /solr/configs/conf1 [junit4] 2> 3 /solr/collections/SolrCloudSnapshots_restored/state.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 5 /solr/clusterstate.json [junit4] 2> 4 /solr/collections/SolrCloudSnapshots/state.json [junit4] 2> 2 /solr/overseer_elect/election/97743363228368903-127.0.0.1:34557_solr-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 21 /solr/overseer/queue [junit4] 2> 19 /solr/overseer/collection-queue-work [junit4] 2> 6 /solr/overseer/queue-work [junit4] 2> 5 /solr/live_nodes [junit4] 2> 5 /solr/collections [junit4] 2> [junit4] 2> 2501705 INFO (SUITE-TestSolrCloudSnapshots-seed#[D7D8ADCAF5492F4F]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.core.snapshots.TestSolrCloudSnapshots_D7D8ADCAF5492F4F-001 [junit4] 2> Apr 06, 2017 2:23:42 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=Asserting(Lucene62): {_version_=BlockTreeOrds(blocksize=128), name=FSTOrd50, id=FSTOrd50}, docValues:{}, maxPointsInLeafNode=1709, maxMBSortInHeap=6.068842387583599, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=en, timezone=America/Merida [junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=4,threads=1,free=266393808,total=533200896 [junit4] 2> NOTE: All tests run in this JVM: [TestZkChroot, DataDrivenBlockJoinTest, TestTolerantUpdateProcessorCloud, TestBinaryResponseWriter, RequestLoggingTest, SharedFSAutoReplicaFailoverTest, TestMacros, RuleEngineTest, TestInitParams, TestFieldResource, TestRecovery, LukeRequestHandlerTest, MinimalSchemaTest, TestGeoJSONResponseWriter, TestDFRSimilarityFactory, ParsingFieldUpdateProcessorsTest, BadComponentTest, SpellPossibilityIteratorTest, PingRequestHandlerTest, ResponseHeaderTest, TestConfigsApi, TestImpersonationWithHadoopAuth, SparseHLLTest, TestDistributedMissingSort, CurrencyFieldXmlFileTest, TestPushWriter, FieldAnalysisRequestHandlerTest, JavabinLoaderTest, TestFieldCacheVsDocValues, SolrPluginUtilsTest, NodeMutatorTest, OverseerTest, PrimitiveFieldTypeTest, TestClassNameShortening, MergeStrategyTest, DeleteLastCustomShardedReplicaTest, TestReload, FullSolrCloudDistribCmdsTest, DistributedFacetPivotWhiteBoxTest, TestPointFields, TestMergePolicyConfig, SolrTestCaseJ4Test, TestIndexingPerformance, SolrGangliaReporterTest, TestAddFieldRealTimeGet, ReplicationFactorTest, CloudMLTQParserTest, UpdateParamsTest, HdfsDirectoryFactoryTest, TestSchemaVersionResource, TestInPlaceUpdatesDistrib, TestSolrQueryParser, VersionInfoTest, TestLeaderElectionZkExpiry, CoreSorterTest, TestComplexPhraseQParserPlugin, TestDistribIDF, ActionThrottleTest, ConcurrentDeleteAndCreateCollectionTest, TestManagedResourceStorage, UnloadDistributedZkTest, DebugComponentTest, CdcrReplicationDistributedZkTest, TestLRUStatsCache, CreateCollectionCleanupTest, TestMultiWordSynonyms, DistribDocExpirationUpdateProcessorTest, DirectUpdateHandlerTest, TestSolrDeletionPolicy1, TestDynamicLoading, HttpPartitionTest, QueryParsingTest, HdfsBasicDistributedZkTest, TestSolrQueryResponse, HardAutoCommitTest, CoreAdminHandlerTest, TestDFISimilarityFactory, BigEndianAscendingWordSerializerTest, HdfsRecoveryZkTest, TestReversedWildcardFilterFactory, TestSchemaNameResource, BlockJoinFacetRandomTest, DistributedSuggestComponentTest, HdfsThreadLeakTest, SuggesterTSTTest, TestSegmentSorting, TestSolrJ, TestNumericTerms32, AddBlockUpdateTest, PropertiesRequestHandlerTest, TestIndexSearcher, TemplateUpdateProcessorTest, TestConfigSets, TestEmbeddedSolrServerSchemaAPI, TestSolrConfigHandlerCloud, TestDynamicFieldCollectionResource, AsyncCallRequestStatusResponseTest, TestTestInjection, FieldMutatingUpdateProcessorTest, TestScoreJoinQPNoScore, TriLevelCompositeIdRoutingTest, TestConfig, DistributedExpandComponentTest, TestFieldCacheSanityChecker, TestRequestForwarding, TestStressCloudBlindAtomicUpdates, DistributedVersionInfoTest, TestObjectReleaseTracker, SuggesterTest, TestDocBasedVersionConstraints, TestConfigOverlay, DirectUpdateHandlerOptimizeTest, RecoveryZkTest, TestReplicationHandler, TestSolr4Spatial, StatsComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, TestFunctionQuery, HighlighterTest, SoftAutoCommitTest, TestPseudoReturnFields, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DocValuesMultiTest, CacheHeaderTest, TestSurroundQueryParser, TestQueryUtils, TestWriterPerf, XmlUpdateRequestHandlerTest, RequestHandlersTest, PathHierarchyTokenizerFactoryTest, TestJmxIntegration, JSONWriterTest, BinaryUpdateRequestHandlerTest, TestComponentsName, TestBinaryResponseWriter, HighlighterConfigTest, SOLR749Test, TestQuerySenderNoQuery, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest, MultiTermTest, TestBinaryField, TestSearchPerf, TestElisionMultitermQuery, OutputWriterTest, ExternalFileFieldSortTest, DirectSolrConnectionTest, TestXIncludeConfig, TestIBSimilarityFactory, TestFastWriter, TimeZoneUtilsTest, ResourceLoaderTest, PluginInfoTest, DateMathParserTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, DOMUtilTest, SystemInfoHandlerTest, CircularListTest, TestCrossCoreJoin, TestHighlightDedupGrouping, TestTolerantSearch, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, AliasIntegrationTest, CdcrReplicationHandlerTest, CdcrRequestHandlerTest, CdcrVersionReplicationTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionTooManyReplicasTest, DeleteShardTest, LeaderFailoverAfterPartitionTest, OverseerCollectionConfigSetProcessorTest, OverseerModifyCollectionTest, OverseerStatusTest, PeerSyncReplicationTest, RecoveryAfterSoftCommitTest, ShardSplitTest, TestReplicaProperties, TestSizeLimitedDistributedMap, TlogReplayBufferedWhileIndexingTest, HdfsCollectionsAPIDistributedZkTest, HdfsRestartWhileUpdatingTest, HdfsSyncSliceTest, HdfsUnloadDistributedZkTest, HdfsWriteToMultipleCollectionsTest, StressHdfsTest, CachingDirectoryFactoryTest, ConfigureRecoveryStrategyTest, DirectoryFactoryTest, TestConfigSetProperties, TestCustomStream, TestSolrDynamicMBean, TestSolrXml, TestSolrCloudSnapshots] [junit4] Completed [574/702 (1!)] on J2 in 61.51s, 1 test, 1 error <<< FAILURES! [...truncated 43716 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
