lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-6.6-Linux (64bit/jdk1.8.0_144) - Build # 105 - Still Unstable!
Date Mon, 28 Aug 2017 04:51:52 GMT
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/105/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseSerialGC

2 tests failed.
FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI

Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}

Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
	at __randomizedtesting.SeedInfo.seed([F3B111E9CE2D632F:BBC4655DC81E4CBA]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
	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:748)


FAILED:  org.apache.solr.core.snapshots.TestSolrCloudSnapshots.testSnapshots

Error Message:
expected:<4> but was:<3>

Stack Trace:
java.lang.AssertionError: expected:<4> but was:<3>
	at __randomizedtesting.SeedInfo.seed([F3B111E9CE2D632F:C5FD9576BB746160]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.core.snapshots.TestSolrCloudSnapshots.testSnapshots(TestSolrCloudSnapshots.java:126)
	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:748)




Build Log:
[...truncated 11245 lines...]
   [junit4] Suite: org.apache.solr.core.snapshots.TestSolrCloudSnapshots
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/init-core-data-001
   [junit4]   2> 244742 WARN  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=9 numCloses=9
   [junit4]   2> 244742 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 244742 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
   [junit4]   2> 244743 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001
   [junit4]   2> 244743 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 244743 INFO  (Thread-2730) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 244743 INFO  (Thread-2730) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 244744 ERROR (Thread-2730) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 244843 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:33743
   [junit4]   2> 244852 INFO  (jetty-launcher-1283-thread-2) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 244852 INFO  (jetty-launcher-1283-thread-3) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 244852 INFO  (jetty-launcher-1283-thread-1) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 244852 INFO  (jetty-launcher-1283-thread-4) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 244869 INFO  (jetty-launcher-1283-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@d879348{/solr,null,AVAILABLE}
   [junit4]   2> 244870 INFO  (jetty-launcher-1283-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@66dd1645{/solr,null,AVAILABLE}
   [junit4]   2> 244871 INFO  (jetty-launcher-1283-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@6d75cad9{HTTP/1.1,[http/1.1]}{127.0.0.1:45677}
   [junit4]   2> 244871 INFO  (jetty-launcher-1283-thread-2) [    ] o.e.j.s.Server Started @246325ms
   [junit4]   2> 244871 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45677}
   [junit4]   2> 244872 ERROR (jetty-launcher-1283-thread-2) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.6.1
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@219d97ff{/solr,null,AVAILABLE}
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-28T04:08:58.145Z
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.e.j.s.AbstractConnector Started ServerConnector@fa0bdf5{HTTP/1.1,[http/1.1]}{127.0.0.1:37991}
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.e.j.s.Server Started @246326ms
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37991}
   [junit4]   2> 244872 ERROR (jetty-launcher-1283-thread-3) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.6.1
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244872 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-28T04:08:58.145Z
   [junit4]   2> 244876 INFO  (jetty-launcher-1283-thread-4) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@11e61e3{/solr,null,AVAILABLE}
   [junit4]   2> 244876 INFO  (jetty-launcher-1283-thread-4) [    ] o.e.j.s.AbstractConnector Started ServerConnector@79235255{HTTP/1.1,[http/1.1]}{127.0.0.1:42341}
   [junit4]   2> 244878 INFO  (jetty-launcher-1283-thread-4) [    ] o.e.j.s.Server Started @246332ms
   [junit4]   2> 244878 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42341}
   [junit4]   2> 244879 ERROR (jetty-launcher-1283-thread-4) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244879 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.6.1
   [junit4]   2> 244879 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244879 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244879 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-28T04:08:58.152Z
   [junit4]   2> 244879 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244880 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244884 INFO  (jetty-launcher-1283-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@3c9d617e{HTTP/1.1,[http/1.1]}{127.0.0.1:40697}
   [junit4]   2> 244884 INFO  (jetty-launcher-1283-thread-1) [    ] o.e.j.s.Server Started @246338ms
   [junit4]   2> 244884 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40697}
   [junit4]   2> 244885 ERROR (jetty-launcher-1283-thread-1) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244885 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.6.1
   [junit4]   2> 244885 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244885 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244885 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-08-28T04:08:58.158Z
   [junit4]   2> 244886 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244895 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 244895 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244895 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 244896 INFO  (jetty-launcher-1283-thread-4) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33743/solr
   [junit4]   2> 244896 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 244897 INFO  (jetty-launcher-1283-thread-3) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33743/solr
   [junit4]   2> 244901 INFO  (jetty-launcher-1283-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33743/solr
   [junit4]   2> 244915 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 244918 INFO  (jetty-launcher-1283-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33743/solr
   [junit4]   2> 244922 INFO  (jetty-launcher-1283-thread-4) [n:127.0.0.1:42341_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 244922 INFO  (jetty-launcher-1283-thread-4) [n:127.0.0.1:42341_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42341_solr
   [junit4]   2> 244924 INFO  (jetty-launcher-1283-thread-4) [n:127.0.0.1:42341_solr    ] o.a.s.c.Overseer Overseer (id=98559153800282119-127.0.0.1:42341_solr-n_0000000000) starting
   [junit4]   2> 244924 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from client sessionid 0x15e270737a10008, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 244930 INFO  (jetty-launcher-1283-thread-3) [n:127.0.0.1:37991_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 244931 INFO  (jetty-launcher-1283-thread-3) [n:127.0.0.1:37991_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37991_solr
   [junit4]   2> 244935 INFO  (jetty-launcher-1283-thread-2) [n:127.0.0.1:45677_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 244936 INFO  (jetty-launcher-1283-thread-2) [n:127.0.0.1:45677_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 244937 INFO  (jetty-launcher-1283-thread-2) [n:127.0.0.1:45677_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45677_solr
   [junit4]   2> 244940 INFO  (jetty-launcher-1283-thread-4) [n:127.0.0.1:42341_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42341_solr
   [junit4]   2> 244974 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 244974 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
   [junit4]   2> 244981 INFO  (OverseerStateUpdate-98559153800282119-127.0.0.1:42341_solr-n_0000000000) [n:127.0.0.1:42341_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 244988 INFO  (jetty-launcher-1283-thread-1) [n:127.0.0.1:40697_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 244989 INFO  (jetty-launcher-1283-thread-1) [n:127.0.0.1:40697_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 244991 INFO  (jetty-launcher-1283-thread-1) [n:127.0.0.1:40697_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40697_solr
   [junit4]   2> 244991 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 244991 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 244992 INFO  (zkCallback-1298-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 245003 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 245034 INFO  (jetty-launcher-1283-thread-2) [n:127.0.0.1:45677_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node2/.
   [junit4]   2> 245035 INFO  (jetty-launcher-1283-thread-3) [n:127.0.0.1:37991_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node3/.
   [junit4]   2> 245069 INFO  (jetty-launcher-1283-thread-4) [n:127.0.0.1:42341_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node4/.
   [junit4]   2> 245070 INFO  (jetty-launcher-1283-thread-1) [n:127.0.0.1:40697_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node1/.
   [junit4]   2> 245116 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 245116 INFO  (SUITE-TestSolrCloudSnapshots-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33743/solr ready
   [junit4]   2> 245154 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSnapshots
   [junit4]   2> 245162 INFO  (qtp2126451477-5639) [n:127.0.0.1:37991_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> 245168 INFO  (OverseerThreadFactory-1143-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_solr    ] o.a.s.c.CreateCollectionCmd Create collection SolrCloudSnapshots
   [junit4]   2> 245380 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 245380 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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> 245380 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245381 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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> 245381 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245381 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245381 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 245382 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245491 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_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> 245491 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_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> 245491 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_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> 245491 INFO  (zkCallback-1298-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_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> 246407 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
   [junit4]   2> 246414 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
   [junit4]   2> 246418 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
   [junit4]   2> 246450 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard1_replica1] Schema name=minimal
   [junit4]   2> 246452 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard1_replica2] Schema name=minimal
   [junit4]   2> 246452 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard2_replica1] Schema name=minimal
   [junit4]   2> 246452 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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> 246452 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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> 246453 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246453 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node4/SolrCloudSnapshots_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node4/./SolrCloudSnapshots_shard1_replica1/data/]
   [junit4]   2> 246455 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
   [junit4]   2> 246463 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.IndexSchema [SolrCloudSnapshots_shard2_replica2] Schema name=minimal
   [junit4]   2> 246464 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246464 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246465 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246465 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node2/SolrCloudSnapshots_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node2/./SolrCloudSnapshots_shard1_replica2/data/]
   [junit4]   2> 246465 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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> 246465 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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> 246466 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246466 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node1/SolrCloudSnapshots_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node1/./SolrCloudSnapshots_shard2_replica2/data/]
   [junit4]   2> 246471 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246471 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246472 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246472 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [[SolrCloudSnapshots_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node3/SolrCloudSnapshots_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/]
   [junit4]   2> 246551 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246551 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246552 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246555 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246565 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3a4389e1[SolrCloudSnapshots_shard1_replica2] main]
   [junit4]   2> 246565 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246565 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246565 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246566 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246566 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 246566 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246566 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246568 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3aa774b3[SolrCloudSnapshots_shard2_replica1] main]
   [junit4]   2> 246569 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246569 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246569 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 246571 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246571 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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> 246572 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246572 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246573 INFO  (searcherExecutor-1155-thread-1-processing-n:127.0.0.1:37991_solr x:SolrCloudSnapshots_shard2_replica1 s:shard2 c:SolrCloudSnapshots) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica1] Registered new searcher Searcher@3aa774b3[SolrCloudSnapshots_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246573 INFO  (searcherExecutor-1153-thread-1-processing-n:127.0.0.1:45677_solr x:SolrCloudSnapshots_shard1_replica2 s:shard1 c:SolrCloudSnapshots) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica2] Registered new searcher Searcher@3a4389e1[SolrCloudSnapshots_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246573 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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 1576946462722359296
   [junit4]   2> 246574 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74169f1a[SolrCloudSnapshots_shard1_replica1] main]
   [junit4]   2> 246578 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246578 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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> 246578 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246578 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246579 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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 1576946462728650752
   [junit4]   2> 246580 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@6aa6fd20[SolrCloudSnapshots_shard2_replica2] main]
   [junit4]   2> 246586 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246591 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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> 246591 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 246591 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246592 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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 1576946462742282240
   [junit4]   2> 246593 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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> 246593 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 246593 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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 1576946462743330816
   [junit4]   2> 246593 INFO  (searcherExecutor-1152-thread-1-processing-n:127.0.0.1:42341_solr x:SolrCloudSnapshots_shard1_replica1 s:shard1 c:SolrCloudSnapshots) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1] Registered new searcher Searcher@74169f1a[SolrCloudSnapshots_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246594 INFO  (searcherExecutor-1154-thread-1-processing-n:127.0.0.1:40697_solr x:SolrCloudSnapshots_shard2_replica2 s:shard2 c:SolrCloudSnapshots) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica2] Registered new searcher Searcher@6aa6fd20[SolrCloudSnapshots_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246623 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 246623 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246623 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45677/solr/SolrCloudSnapshots_shard1_replica2/
   [junit4]   2> 246623 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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:45677/solr START replicas=[http://127.0.0.1:42341/solr/SolrCloudSnapshots_shard1_replica1/] nUpdates=100
   [junit4]   2> 246627 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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:45677/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 246631 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 246631 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246631 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:37991/solr/SolrCloudSnapshots_shard2_replica1/
   [junit4]   2> 246631 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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:37991/solr START replicas=[http://127.0.0.1:40697/solr/SolrCloudSnapshots_shard2_replica2/] nUpdates=100
   [junit4]   2> 246645 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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:37991/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 246648 INFO  (qtp1723375428-5609) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 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> 246649 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246649 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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> 246649 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 246660 INFO  (qtp1732446423-5615) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 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=9
   [junit4]   2> 246661 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246661 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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> 246661 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 246664 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:37991/solr/SolrCloudSnapshots_shard2_replica1/ shard2
   [junit4]   2> 246665 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45677/solr/SolrCloudSnapshots_shard1_replica2/ shard1
   [junit4]   2> 246767 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_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> 246767 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_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> 246767 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_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> 246768 INFO  (zkCallback-1298-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_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> 246815 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2  x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 246815 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1  x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 246816 INFO  (qtp839499304-5626) [n:127.0.0.1:45677_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=1436
   [junit4]   2> 246817 INFO  (qtp2126451477-5640) [n:127.0.0.1:37991_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=1435
   [junit4]   2> 246920 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_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> 246920 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_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> 246920 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_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> 246920 INFO  (zkCallback-1298-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_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> 247628 INFO  (qtp1723375428-5619) [n:127.0.0.1:40697_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=2247
   [junit4]   2> 247633 INFO  (qtp1732446423-5630) [n:127.0.0.1:42341_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=2253
   [junit4]   2> 247654 INFO  (qtp2126451477-5639) [n:127.0.0.1:37991_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> 247763 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_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> 247763 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_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> 247765 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_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> 247765 INFO  (zkCallback-1298-thread-1-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_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> 248655 INFO  (qtp2126451477-5639) [n:127.0.0.1:37991_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=3492
   [junit4]   2> 248728 INFO  (qtp1732446423-5633) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica1]  webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1576946464918077440&distrib.from=http://127.0.0.1:45677/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1576946464918077440)} 0 21
   [junit4]   2> 248733 INFO  (qtp1723375428-5609) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica2]  webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1576946464942194688&distrib.from=http://127.0.0.1:37991/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:* (-1576946464942194688)} 0 3
   [junit4]   2> 248734 INFO  (qtp2126451477-5613) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 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:45677/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1576946464942194688)} 0 43
   [junit4]   2> 248734 INFO  (qtp839499304-5625) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2]  webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1576946464918077440)} 0 70
   [junit4]   2> 248734 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.h.BackupRestoreUtils Indexing 12 test docs
   [junit4]   2> 248781 INFO  (qtp1732446423-5606) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 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:45677/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2}{add=[0 (1576946465028177920), 1 (1576946465029226496), 4 (1576946465029226497), 8 (1576946465029226498), 10 (1576946465030275072), 11 (1576946465030275073)]} 0 1
   [junit4]   2> 248788 INFO  (qtp839499304-5635) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard1_replica2]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1576946465028177920), 1 (1576946465029226496), 4 (1576946465029226497), 8 (1576946465029226498), 10 (1576946465030275072), 11 (1576946465030275073)]} 0 16
   [junit4]   2> 248808 INFO  (qtp1723375428-5607) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 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:37991/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2}{add=[2 (1576946465028177920), 3 (1576946465038663680), 5 (1576946465038663681), 6 (1576946465038663682), 7 (1576946465038663683), 9 (1576946465038663684)]} 0 23
   [junit4]   2> 248810 INFO  (qtp2126451477-5641) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1576946465028177920), 3 (1576946465038663680), 5 (1576946465038663681), 6 (1576946465038663682), 7 (1576946465038663683), 9 (1576946465038663684)]} 0 38
   [junit4]   2> 248814 INFO  (qtp839499304-5610) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 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> 248814 INFO  (qtp839499304-5610) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@679f1359
   [junit4]   2> 248833 INFO  (qtp1732446423-5617) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 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> 248833 INFO  (qtp1732446423-5617) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@4fca5f43
   [junit4]   2> 248867 INFO  (qtp1723375428-5621) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 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> 248867 INFO  (qtp1723375428-5621) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@470e5e08
   [junit4]   2> 248868 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 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> 248869 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@53466214
   [junit4]   2> 248939 INFO  (qtp839499304-5610) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@497c7a75[SolrCloudSnapshots_shard1_replica2] main]
   [junit4]   2> 248940 INFO  (qtp839499304-5610) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 248940 INFO  (searcherExecutor-1153-thread-1-processing-n:127.0.0.1:45677_solr x:SolrCloudSnapshots_shard1_replica2 s:shard1 c:SolrCloudSnapshots r:core_node1) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 x:SolrCloudSnapshots_shard1_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica2] Registered new searcher Searcher@497c7a75[SolrCloudSnapshots_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C6)))}
   [junit4]   2> 248940 INFO  (qtp839499304-5610) [n:127.0.0.1:45677_solr c:SolrCloudSnapshots s:shard1 r:core_node1 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:37991/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 126
   [junit4]   2> 249018 INFO  (qtp1732446423-5617) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ea9b9df[SolrCloudSnapshots_shard1_replica1] main]
   [junit4]   2> 249018 INFO  (qtp1732446423-5617) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 249019 INFO  (searcherExecutor-1152-thread-1-processing-n:127.0.0.1:42341_solr x:SolrCloudSnapshots_shard1_replica1 s:shard1 c:SolrCloudSnapshots r:core_node2) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1] Registered new searcher Searcher@6ea9b9df[SolrCloudSnapshots_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C6)))}
   [junit4]   2> 249019 INFO  (qtp1732446423-5617) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 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:37991/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 186
   [junit4]   2> 249054 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@72251385[SolrCloudSnapshots_shard2_replica1] main]
   [junit4]   2> 249055 INFO  (searcherExecutor-1155-thread-1-processing-n:127.0.0.1:37991_solr x:SolrCloudSnapshots_shard2_replica1 s:shard2 c:SolrCloudSnapshots r:core_node4) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica1] Registered new searcher Searcher@72251385[SolrCloudSnapshots_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C6)))}
   [junit4]   2> 249055 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 249055 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 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:37991/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 186
   [junit4]   2> 249063 INFO  (qtp1723375428-5621) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@23cb8445[SolrCloudSnapshots_shard2_replica2] main]
   [junit4]   2> 249063 INFO  (qtp1723375428-5621) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 249063 INFO  (searcherExecutor-1154-thread-1-processing-n:127.0.0.1:40697_solr x:SolrCloudSnapshots_shard2_replica2 s:shard2 c:SolrCloudSnapshots r:core_node3) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.SolrCore [SolrCloudSnapshots_shard2_replica2] Registered new searcher Searcher@23cb8445[SolrCloudSnapshots_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.6.1):C6)))}
   [junit4]   2> 249063 INFO  (qtp1723375428-5621) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 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:37991/solr/SolrCloudSnapshots_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 196
   [junit4]   2> 249064 INFO  (qtp2126451477-5639) [n:127.0.0.1:37991_solr c:SolrCloudSnapshots s:shard2 r:core_node4 x:SolrCloudSnapshots_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [SolrCloudSnapshots_shard2_replica1]  webapp=/solr path=/update params={_stateVer_=SolrCloudSnapshots:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 251
   [junit4]   2> 249069 INFO  (qtp1732446423-5631) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard1_replica1]  webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=SolrCloudSnapshots:4&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:42341/solr/SolrCloudSnapshots_shard1_replica1/|http://127.0.0.1:45677/solr/SolrCloudSnapshots_shard1_replica2/&rows=10&version=2&q=*:*&NOW=1503893342339&isShard=true&wt=javabin} hits=6 status=0 QTime=0
   [junit4]   2> 249070 INFO  (qtp1723375428-5620) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica2]  webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=SolrCloudSnapshots:4&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:40697/solr/SolrCloudSnapshots_shard2_replica2/|http://127.0.0.1:37991/solr/SolrCloudSnapshots_shard2_replica1/&rows=10&version=2&q=*:*&NOW=1503893342339&isShard=true&wt=javabin} hits=6 status=0 QTime=0
   [junit4]   2> 249073 INFO  (qtp1723375428-5609) [n:127.0.0.1:40697_solr c:SolrCloudSnapshots s:shard2 r:core_node3 x:SolrCloudSnapshots_shard2_replica2] o.a.s.c.S.Request [SolrCloudSnapshots_shard2_replica2]  webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=SolrCloudSnapshots:4&shards.purpose=64&NOW=1503893342339&ids=2,3,5,6,7,9&isShard=true&shard.url=http://127.0.0.1:40697/solr/SolrCloudSnapshots_shard2_replica2/|http://127.0.0.1:37991/solr/SolrCloudSnapshots_shard2_replica1/&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 249074 INFO  (qtp1732446423-5631) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard1_replica1]  webapp=/solr path=/select params={q=*:*&df=text&distrib=false&_stateVer_=SolrCloudSnapshots:4&shards.purpose=64&NOW=1503893342339&ids=0,1,4,8&isShard=true&shard.url=http://127.0.0.1:42341/solr/SolrCloudSnapshots_shard1_replica1/|http://127.0.0.1:45677/solr/SolrCloudSnapshots_shard1_replica2/&wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 249075 INFO  (qtp1732446423-5633) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.S.Request [SolrCloudSnapshots_shard1_replica1]  webapp=/solr path=/select params={q=*:*&_stateVer_=SolrCloudSnapshots:4&wt=javabin&version=2} hits=12 status=0 QTime=9
   [junit4]   2> 249091 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@79235255{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 249099 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1898007880
   [junit4]   2> 249100 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 249100 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
   [junit4]   2> 249100 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
   [junit4]   2> 249132 INFO  (coreCloseExecutor-1172-thread-1) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.c.SolrCore [SolrCloudSnapshots_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ceba0fa
   [junit4]   2> 249145 INFO  (coreCloseExecutor-1172-thread-1) [n:127.0.0.1:42341_solr c:SolrCloudSnapshots s:shard1 r:core_node2 x:SolrCloudSnapshots_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.SolrCloudSnapshots.shard1.replica1
   [junit4]   2> 249147 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.c.Overseer Overseer (id=98559153800282119-127.0.0.1:42341_solr-n_0000000000) closing
   [junit4]   2> 249148 INFO  (OverseerStateUpdate-98559153800282119-127.0.0.1:42341_solr-n_0000000000) [n:127.0.0.1:42341_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:42341_solr
   [junit4]   2> 249155 INFO  (zkCallback-1313-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 249155 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 249156 INFO  (zkCallback-1305-thread-1-processing-n:127.0.0.1:40697_solr) [n:127.0.0.1:40697_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 249156 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37991_solr
   [junit4]   2> 249156 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.Overseer Overseer (id=98559153800282121-127.0.0.1:37991_solr-n_0000000001) starting
   [junit4]   2> 249171 INFO  (zkCallback-1300-thread-2-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 250655 WARN  (zkCallback-1298-thread-2-processing-n:127.0.0.1:42341_solr) [n:127.0.0.1:42341_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 250657 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@11e61e3{/solr,null,UNAVAILABLE}
   [junit4]   2> 255662 INFO  (qtp2126451477-5612) [n:127.0.0.1:37991_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createsnapshot with params name=SolrCloudSnapshots&action=CREATESNAPSHOT&collection=SolrCloudSnapshots&commitName=nbyr&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 255667 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Creating a snapshot for collection=SolrCloudSnapshots with commitName=nbyr
   [junit4]   2> 255669 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Created a ZK path to store snapshot information for collection=SolrCloudSnapshots with commitName=nbyr
   [junit4]   2> 255671 INFO  (qtp839499304-5616) [n:127.0.0.1:45677_solr    ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named nbyr for core SolrCloudSnapshots_shard1_replica2 associated with index commit with generation 2 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node2/./SolrCloudSnapshots_shard1_replica2/data/index/
   [junit4]   2> 255696 INFO  (qtp839499304-5616) [n:127.0.0.1:45677_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=nbyr&wt=javabin&version=2} status=0 QTime=25
   [junit4]   2> 255697 INFO  (qtp2126451477-5608) [n:127.0.0.1:37991_solr    ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named nbyr for core SolrCloudSnapshots_shard2_replica1 associated with index commit with generation 2 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/index/
   [junit4]   2> 255698 ERROR (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: http://127.0.0.1:42341/solr
   [junit4]   2> org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:42341/solr
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:619)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268)
   [junit4]   2> 	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
   [junit4]   2> 	at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:163)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2> 	at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> Caused by: java.net.ConnectException: Connection refused (Connection refused)
   [junit4]   2> 	at java.net.PlainSocketImpl.socketConnect(Native Method)
   [junit4]   2> 	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
   [junit4]   2> 	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
   [junit4]   2> 	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
   [junit4]   2> 	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
   [junit4]   2> 	at java.net.Socket.connect(Socket.java:589)
   [junit4]   2> 	at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:117)
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:177)
   [junit4]   2> 	at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304)
   [junit4]   2> 	at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:611)
   [junit4]   2> 	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:446)
   [junit4]   2> 	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:515)
   [junit4]   2> 	... 12 more
   [junit4]   2> 255702 INFO  (qtp2126451477-5608) [n:127.0.0.1:37991_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=nbyr&wt=javabin&version=2} status=0 QTime=4
   [junit4]   2> 255711 INFO  (qtp1723375428-5611) [n:127.0.0.1:40697_solr    ] o.a.s.c.s.SolrSnapshotMetaDataManager Creating the snapshot named nbyr for core SolrCloudSnapshots_shard2_replica2 associated with index commit with generation 2 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node1/./SolrCloudSnapshots_shard2_replica2/data/index/
   [junit4]   2> 255716 INFO  (qtp1723375428-5611) [n:127.0.0.1:40697_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=nbyr&wt=javabin&version=2} status=0 QTime=5
   [junit4]   2> 255718 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName nbyr is created successfully for core SolrCloudSnapshots_shard1_replica2
   [junit4]   2> 255718 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName nbyr is created successfully for core SolrCloudSnapshots_shard2_replica1
   [junit4]   2> 255718 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Snapshot with commitName nbyr is created successfully for core SolrCloudSnapshots_shard2_replica2
   [junit4]   2> 255718 WARN  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Unable to create a snapshot with name nbyr for following cores [SolrCloudSnapshots_shard1_replica1]
   [junit4]   2> 255719 INFO  (OverseerThreadFactory-1175-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_solr    ] o.a.s.c.CreateSnapshotCmd Saved following snapshot information for collection=SolrCloudSnapshots with commitName=nbyr in Zookeeper : {name=nbyr,status=Successful,creationDate=1503893348939,replicas={SolrCloudSnapshots_shard1_replica2={core=SolrCloudSnapshots_shard1_replica2,indexDirPath=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node2/./SolrCloudSnapshots_shard1_replica2/data/index/,generation=2,shard_id=shard1,leader=true,files=[_0.si, _0_LuceneVarGapDocFreqInterval_0.pos, _0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene50_0.pos, segments_2, _0.nvd, _0_LuceneVarGapDocFreqInterval_0.tib, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0_LuceneVarGapDocFreqInterval_0.tiv, _0.nvm, _0_LuceneVarGapDocFreqInterval_0.doc, _0.fnm]},SolrCloudSnapshots_shard2_replica1={core=SolrCloudSnapshots_shard2_replica1,indexDirPath=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node3/./SolrCloudSnapshots_shard2_replica1/data/index/,generation=2,shard_id=shard2,leader=true,files=[_0.si, _0_LuceneVarGapDocFreqInterval_0.pos, _0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene50_0.pos, segments_2, _0.nvd, _0_LuceneVarGapDocFreqInterval_0.tib, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0_LuceneVarGapDocFreqInterval_0.tiv, _0.nvm, _0_LuceneVarGapDocFreqInterval_0.doc, _0.fnm]},SolrCloudSnapshots_shard2_replica2={core=SolrCloudSnapshots_shard2_replica2,indexDirPath=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J0/temp/solr.core.snapshots.TestSolrCloudSnapshots_F3B111E9CE2D632F-001/tempDir-001/node1/./SolrCloudSnapshots_shard2_replica2/data/index/,generation=2,shard_id=shard2,leader=false,files=[_0.si, _0_LuceneVarGapDocFreqInterval_0.pos, _0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene50_0.pos, segments_2, _0.nvd, _0_LuceneVarGapDocFreqInterval_0.tib, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0_LuceneVarGapDocFreqInterval_0.tiv, _0.nvm, _0_LuceneVarGapDocFreqInterval_0.doc, _0.fnm]}}}
   [junit4]   2> 255721 INFO  (qtp2126451477-5612) [n:127.0.0.1:37991_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=SolrCloudSnapshots&action=CREATESNAPSHOT&collection=SolrCloudSnapshots&commitName=nbyr&wt=javabin&version=2} status=0 QTime=59
   [junit4]   2> 255726 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_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> 255728 INFO  (qtp2126451477-5624) [n:127.0.0.1:37991_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> 255729 INFO  (TEST-TestSolrCloudSnapshots.testSnapshots-seed#[F3B111E9CE2D632F]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSnapshots
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSolrCloudSnapshots -Dtests.method=testSnapshots -Dtests.seed=F3B111E9CE2D632F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ro-RO -Dtests.timezone=Pacific/Port_Moresby -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 10.6s J0 | TestSolrCloudSnapshots.testSnapshots <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<4> but was:<3>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F3B111E9CE2D632F:C5FD9576BB746160]:0)
   [junit4]    > 	at org.apache.solr.core.snapshots.TestSolrCloudSnapshots.testSnapshots(TestSolrCloudSnapshots.java:126)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 255760 INFO  (jetty-closer-1284-thread-1) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@fa0bdf5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 255774 INFO  (jetty-closer-1284-thread-1) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1844087932
   [junit4]   2> 255774 INFO  (jetty-closer-1284-thread-4) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@3c9d617e{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-4) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=633921281
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-2) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@6d75cad9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-4) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-2) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=999737684
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-4) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-4) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
   [junit4]   2> 255775 INFO  (jetty-closer-1284-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
   [junit4]   2> 255777 INFO  (jetty-closer-1284-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 255777 INFO  (jetty-closer-1284-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
   [junit4]   2> 255777 INFO  (jetty-closer-1284-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
   [junit4]   2> 255780 INFO  (zkCallback-1307-thread-1-processing-n:127.0.0.1:45677_solr) [n:127.0.0.1:45677_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> 255780 INFO  (zkCallback-1300-thread-1-processing-n:127.0.0.1:37991_solr) [n:127.0.0.1:37991_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> 255780 INFO  (zkCallb

[...truncated too long message...]

leAdmin(HttpSolrCall.java:748)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:361)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:305)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
   [junit4]   2> 	at org.eclipse.jetty.server.Server.handle(Server.java:534)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
   [junit4]   2> 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
   [junit4]   2> 	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 950126 INFO  (qtp563223369-6995) [n:127.0.0.1:39669_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:42823_solr&onlyIfLeaderActive=true&core=addReplicaColl_shard1_replica1&coreNodeName=core_node7&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=400 QTime=18003
   [junit4]   2> 951029 WARN  (zkCallback-1123-thread-1-processing-n:127.0.0.1:33093_solr) [n:127.0.0.1:33093_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 951029 WARN  (zkCallback-1105-thread-2-processing-n:127.0.0.1:42823_solr) [n:127.0.0.1:42823_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 951029 INFO  (jetty-closer-1084-thread-1) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@156d4e30{/solr,null,UNAVAILABLE}
   [junit4]   2> 951029 INFO  (jetty-closer-1084-thread-3) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@48345028{/solr,null,UNAVAILABLE}
   [junit4]   2> 951030 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 951030 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33887 33887
   [junit4]   2> 956060 INFO  (Thread-1941) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33887 33887
   [junit4]   2> 956060 WARN  (Thread-1941) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	26	/solr/aliases.json
   [junit4]   2> 	26	/solr/clusterprops.json
   [junit4]   2> 	23	/solr/configs/conf
   [junit4]   2> 	5	/solr/security.json
   [junit4]   2> 	2	/solr/configs/conf2
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	185	/solr/clusterstate.json
   [junit4]   2> 	4	/solr/collections/nodes_used_collection/state.json
   [junit4]   2> 	4	/solr/collections/addReplicaColl/state.json
   [junit4]   2> 	4	/solr/collections/reloaded_collection/state.json
   [junit4]   2> 	3	/solr/collections/acollectionafterbaddelete/state.json
   [junit4]   2> 	2	/solr/collections/onlyinzk/state.json
   [junit4]   2> 	2	/solr/collections/awhollynewcollection_0/state.json
   [junit4]   2> 	2	/solr/overseer_elect/election/98559194515177481-127.0.0.1:39669_solr-n_0000000001
   [junit4]   2> 	2	/solr/collections/addReplicaColl/leader_elect/shard1/election/98559194515177489-core_node2-n_0000000001
   [junit4]   2> 	2	/solr/collections/halfdeletedcollection/state.json
   [junit4]   2> 	2	/solr/collections/addReplicaColl/leader_elect/shard2/election/98559194515177484-core_node1-n_0000000000
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	392	/solr/collections
   [junit4]   2> 	35	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> 956060 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F3B111E9CE2D632F]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F3B111E9CE2D632F-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=PostingsFormat(name=LuceneVarGapDocFreqInterval), id=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, maxPointsInLeafNode=1465, maxMBSortInHeap=6.888961080852251, sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=bg, timezone=Africa/Mogadishu
   [junit4]   2> NOTE: Linux 4.10.0-27-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=89331232,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [TestDFISimilarityFactory, DistributedTermsComponentTest, TestFieldTypeResource, SliceStateTest, SparseHLLTest, TestFileDictionaryLookup, HdfsThreadLeakTest, TermVectorComponentTest, TestLeaderElectionZkExpiry, DistributedMLTComponentTest, TestSmileRequest, TestGraphMLResponseWriter, DistributedFacetPivotLargeTest, SpellCheckCollatorTest, SolrCloudExampleTest, SolrCoreMetricManagerTest, OverseerTaskQueueTest, SearchHandlerTest, TestNumericTerms64, HdfsDirectoryTest, TestFastOutputStream, SuggesterFSTTest, LeaderInitiatedRecoveryOnShardRestartTest, TestReqParamsAPI, IndexBasedSpellCheckerTest, TestCustomDocTransformer, TestDistributedStatsComponentCardinality, SimplePostToolTest, DocValuesTest, URLClassifyProcessorTest, TestExclusionRuleCollectionAccess, TestImpersonationWithHadoopAuth, TestLRUCache, TestScoreJoinQPNoScore, TestInitParams, TestHashPartitioner, TestUseDocValuesAsStored2, SortByFunctionTest, SolrCmdDistributorTest, HdfsWriteToMultipleCollectionsTest, TestSchemaManager, TestFieldCacheWithThreads, SystemInfoHandlerTest, PKIAuthenticationIntegrationTest, TestReloadDeadlock, PreAnalyzedFieldManagedSchemaCloudTest, MetricsHandlerTest, MoreLikeThisHandlerTest, LeaderFailoverAfterPartitionTest, TestRTGBase, ClassificationUpdateProcessorFactoryTest, DistributedQueueTest, TestExceedMaxTermLength, TestUpdate, TestSchemaSimilarityResource, SegmentsInfoRequestHandlerTest, CursorMarkTest, ShardRoutingTest, TestSearchPerf, TestGraphTermsQParserPlugin, BasicFunctionalityTest, TestConfigSetsAPIExclusivity, IndexSchemaRuntimeFieldTest, TestSolrCoreSnapshots, TestFieldCache, DocValuesMissingTest, TestCustomSort, TestLRUStatsCache, CdcrBootstrapTest, TestSolrDynamicMBean, SolrIndexSplitterTest, PeerSyncWithIndexFingerprintCachingTest, TestRequestForwarding, ZkControllerTest, OpenCloseCoreStressTest, TestWordDelimiterFilterFactory, TestLockTree, TestSolrIndexConfig, HdfsDirectoryFactoryTest, DistributedFacetPivotSmallTest, ZkCLITest, SolrIndexConfigTest, JSONWriterTest, IndexSchemaTest, JsonLoaderTest, ChaosMonkeySafeLeaderTest, TestSystemIdResolver, ConnectionManagerTest, TestEmbeddedSolrServerConstructors, SoftAutoCommitTest, InfixSuggestersTest, OverseerModifyCollectionTest, TestFieldCollectionResource, TestConfigSets, MultiTermTest, SolrJmxReporterCloudTest, ConnectionReuseTest, TestJsonFacetRefinement, AssignTest, TestCollectionAPIs, TestPerFieldSimilarityWithDefaultOverride, TestTrackingShardHandlerFactory, TestFuzzyAnalyzedSuggestions, TestManagedSchemaAPI, HdfsCollectionsAPIDistributedZkTest, TestLMDirichletSimilarityFactory, HighlighterTest, TestNoOpRegenerator, TestClusterProperties, HttpSolrCallGetCoreTest, LoggingHandlerTest, TestManagedStopFilterFactory, TestDynamicLoading, SampleTest, DistanceFunctionTest, TestInPlaceUpdatesStandalone, CollectionsAPIDistributedZkTest]
   [junit4] Completed [277/713 (2!)] on J1 in 90.01s, 20 tests, 1 failure <<< FAILURES!

[...truncated 44867 lines...]

Mime
View raw message