Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.0/141/

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

Error Message:
Error from server at 
http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1: 
ClusterState says we are the leader 
(http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1), but 
locally we don't think so. Request came from null

Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from 
server at http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1: 
ClusterState says we are the leader 
(http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1), but 
locally we don't think so. Request came from null
        at 
__randomizedtesting.SeedInfo.seed([F02F5FCB4A4B405A:B85A2B7F4C786FCF]:0)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
        at 
org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:458)
        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)
Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at 
http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1: 
ClusterState says we are the leader 
(http://127.0.0.1:42538/solr/awhollynewcollection_0_shard1_replica_n1), but 
locally we don't think so. Request came from null
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:627)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:516)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        ... 1 more


FAILED:  
org.apache.solr.cloud.MoveReplicaHDFSUlogDirTest.testDataDirAndUlogAreMaintained

Error Message:
Could not load collection from ZK: movereplicatest_coll2

Stack Trace:
org.apache.solr.common.SolrException: Could not load collection from ZK: 
movereplicatest_coll2
        at 
__randomizedtesting.SeedInfo.seed([F02F5FCB4A4B405A:DF1CCA18F63BF278]:0)
        at 
org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1114)
        at 
org.apache.solr.common.cloud.ZkStateReader$LazyCollectionRef.get(ZkStateReader.java:647)
        at 
org.apache.solr.common.cloud.ClusterState.getCollectionsMap(ClusterState.java:144)
        at 
org.apache.solr.common.cloud.ClusterStateUtil.waitForAllActiveAndLiveReplicas(ClusterStateUtil.java:72)
        at 
org.apache.solr.common.cloud.ClusterStateUtil.waitForAllActiveAndLiveReplicas(ClusterStateUtil.java:46)
        at 
org.apache.solr.cloud.MoveReplicaHDFSUlogDirTest.testDataDirAndUlogAreMaintained(MoveReplicaHDFSUlogDirTest.java:97)
        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)
Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: 
KeeperErrorCode = Session expired for 
/collections/movereplicatest_coll2/state.json
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
        at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1212)
        at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:357)
        at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:354)
        at 
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
        at 
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:354)
        at 
org.apache.solr.common.cloud.ZkStateReader.fetchCollectionState(ZkStateReader.java:1126)
        at 
org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1112)
        ... 44 more


FAILED:  org.apache.solr.cloud.TestLocalFSCloudBackupRestore.test

Error Message:
Could not load collection from ZK: backuprestore

Stack Trace:
org.apache.solr.common.SolrException: Could not load collection from ZK: 
backuprestore
        at 
__randomizedtesting.SeedInfo.seed([F02F5FCB4A4B405A:787B6011E4B72DA2]:0)
        at 
org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1114)
        at 
org.apache.solr.common.cloud.ZkStateReader$LazyCollectionRef.get(ZkStateReader.java:647)
        at 
org.apache.solr.common.cloud.ClusterState.getCollectionOrNull(ClusterState.java:128)
        at 
org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:108)
        at 
org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.getActiveSliceCount(AbstractCloudBackupRestoreTestCase.java:191)
        at 
org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:123)
        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)
Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: 
KeeperErrorCode = Session expired for /collections/backuprestore/state.json
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
        at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1212)
        at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:357)
        at 
org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:354)
        at 
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
        at 
org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:354)
        at 
org.apache.solr.common.cloud.ZkStateReader.fetchCollectionState(ZkStateReader.java:1126)
        at 
org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateReader.java:1112)
        ... 44 more




Build Log:
[...truncated 11909 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestLocalFSCloudBackupRestore
   [junit4]   2> Creating dataDir: 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/init-core-data-001
   [junit4]   2> 2754423 WARN  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=266 numCloses=266
   [junit4]   2> 2754590 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 2754591 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 2754592 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001
   [junit4]   2> 2754592 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2754592 INFO  (Thread-1960) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2754592 INFO  (Thread-1960) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 2754618 ERROR (Thread-1960) [    ] 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> 2754700 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:33536
   [junit4]   2> 2755009 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2755045 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2755155 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@66f7651c{/solr,null,AVAILABLE}
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@654ba1b1{HTTP/1.1,[http/1.1]}{127.0.0.1:38250}
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.e.j.s.Server Started @2772113ms
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=38250}
   [junit4]   2> 2755156 ERROR (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 2755156 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-09-30T07:09:59.135Z
   [junit4]   2> 2755248 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@6a0521a2{/solr,null,AVAILABLE}
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@ea1be86{HTTP/1.1,[http/1.1]}{127.0.0.1:44215}
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.e.j.s.Server Started @2772206ms
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=44215}
   [junit4]   2> 2755249 ERROR (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 2755249 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-09-30T07:09:59.228Z
   [junit4]   2> 2755264 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2755485 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2755515 INFO  (jetty-launcher-2527-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33536/solr
   [junit4]   2> 2755573 INFO  (jetty-launcher-2527-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33536/solr
   [junit4]   2> 2755948 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 2755949 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:38250_solr
   [junit4]   2> 2755950 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.Overseer Overseer 
(id=98746721801142278-127.0.0.1:38250_solr-n_0000000000) starting
   [junit4]   2> 2756117 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:38250_solr
   [junit4]   2> 2756204 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 2756242 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 2756255 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 2756256 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:44215_solr
   [junit4]   2> 2756307 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 2756347 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 2757105 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757157 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757157 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757158 INFO  (jetty-launcher-2527-thread-1) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/.
   [junit4]   2> 2757696 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757769 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757769 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2757770 INFO  (jetty-launcher-2527-thread-2) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/.
   [junit4]   2> 2758214 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2758214 INFO  
(SUITE-TestLocalFSCloudBackupRestore-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33536/solr ready
   [junit4]   2> 2758413 INFO  
(TEST-TestLocalFSCloudBackupRestore.test-seed#[F02F5FCB4A4B405A]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 2758506 INFO  (qtp980202949-12186) [n:127.0.0.1:38250_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
pullReplicas=1&replicationFactor=1&property.customKey=customValue&collection.configName=conf1&maxShardsPerNode=6&name=backuprestore&nrtReplicas=1&action=CREATE&numShards=2&tlogReplicas=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 2758631 INFO  
(OverseerThreadFactory-2721-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
backuprestore
   [junit4]   2> 2758683 WARN  
(OverseerThreadFactory-2721-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.CreateCollectionCmd Specified number of 
replicas of 3 on collection backuprestore is higher than the number of Solr 
instances currently live or live and part of your createNodeSet(2). It's 
unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 2758940 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:38250/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 2758942 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_t1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44215/solr";,
   [junit4]   2>   "type":"TLOG"} 
   [junit4]   2> 2758975 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_p1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:38250/solr";,
   [junit4]   2>   "type":"PULL"} 
   [junit4]   2> 2758977 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44215/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 2758977 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_t1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:38250/solr";,
   [junit4]   2>   "type":"TLOG"} 
   [junit4]   2> 2758978 INFO  
(OverseerStateUpdate-98746721801142278-127.0.0.1:38250_solr-n_0000000000) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_p1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44215/solr";,
   [junit4]   2>   "type":"PULL"} 
   [junit4]   2> 2759283 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node1&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 2759284 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 2759336 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node4&name=backuprestore_shard2_replica_n1&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 2759337 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 2759344 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node6&name=backuprestore_shard2_replica_p1&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 2759555 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node5&name=backuprestore_shard2_replica_t1&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 2759556 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node2&name=backuprestore_shard1_replica_t1&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 2759557 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_p1&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 2759669 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2759669 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2759670 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2759705 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2760603 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2760683 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.s.IndexSchema [backuprestore_shard1_replica_t1] Schema name=minimal
   [junit4]   2> 2760700 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2760700 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_t1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2760714 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2760730 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2760736 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.core.backuprestore.shard1.replica_t1' (registry 
'solr.core.backuprestore.shard1.replica_t1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2760736 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2760736 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.SolrCore [[backuprestore_shard1_replica_t1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/backuprestore_shard1_replica_t1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/./backuprestore_shard1_replica_t1/data/]
   [junit4]   2> 2760771 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2761010 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2761024 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2761027 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.s.IndexSchema [backuprestore_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 2761029 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2761029 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2761062 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.core.backuprestore.shard1.replica_n1' (registry 
'solr.core.backuprestore.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2761062 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2761062 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.SolrCore [[backuprestore_shard1_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/backuprestore_shard1_replica_n1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/./backuprestore_shard1_replica_n1/data/]
   [junit4]   2> 2761071 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.s.IndexSchema [backuprestore_shard2_replica_p1] Schema name=minimal
   [junit4]   2> 2761073 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2761073 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_p1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2761074 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.core.backuprestore.shard2.replica_p1' (registry 
'solr.core.backuprestore.shard2.replica_p1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2761087 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.s.IndexSchema [backuprestore_shard2_replica_n1] Schema name=minimal
   [junit4]   2> 2761089 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2761089 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2761090 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44215.solr.core.backuprestore.shard2.replica_n1' (registry 
'solr.core.backuprestore.shard2.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2761090 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2761090 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.SolrCore [[backuprestore_shard2_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/backuprestore_shard2_replica_n1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/./backuprestore_shard2_replica_n1/data/]
   [junit4]   2> 2761083 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.s.IndexSchema [backuprestore_shard2_replica_t1] Schema name=minimal
   [junit4]   2> 2761136 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2761137 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_t1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2761137 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.core.backuprestore.shard2.replica_t1' (registry 
'solr.core.backuprestore.shard2.replica_t1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2761137 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2761137 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.SolrCore [[backuprestore_shard2_replica_t1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/backuprestore_shard2_replica_t1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/./backuprestore_shard2_replica_t1/data/]
   [junit4]   2> 2761107 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2761096 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.s.IndexSchema [backuprestore_shard1_replica_p1] Schema name=minimal
   [junit4]   2> 2761149 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2761149 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_p1' using 
configuration from collection backuprestore, trusted=true
   [junit4]   2> 2761149 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_38250.solr.core.backuprestore.shard1.replica_p1' (registry 
'solr.core.backuprestore.shard1.replica_p1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@287d39b
   [junit4]   2> 2761149 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2761149 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.SolrCore [[backuprestore_shard1_replica_p1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/backuprestore_shard1_replica_p1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node2/./backuprestore_shard1_replica_p1/data/]
   [junit4]   2> 2761172 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.SolrCore [[backuprestore_shard2_replica_p1] ] Opening new SolrCore at 
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/backuprestore_shard2_replica_p1],
 
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_F02F5FCB4A4B405A-001/tempDir-001/node1/./backuprestore_shard2_replica_p1/data/]
   [junit4]   2> 2761547 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2761547 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2761818 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2761818 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2761837 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3c434a54[backuprestore_shard1_replica_n1] main]
   [junit4]   2> 2761838 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2761838 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2761839 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2761912 INFO  
(searcherExecutor-2727-thread-1-processing-n:127.0.0.1:38250_solr 
x:backuprestore_shard1_replica_n1 s:shard1 c:backuprestore r:core_node1) 
[n:127.0.0.1:38250_solr c:backuprestore s:shard1 r:core_node1 
x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore 
[backuprestore_shard1_replica_n1] Registered new searcher 
Searcher@3c434a54[backuprestore_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2761912 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1579947556487561216
   [junit4]   2> 2761950 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2761950 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2761985 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 2761986 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2761986 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2761987 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2761987 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2762021 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2762021 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2762022 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1ee295cc[backuprestore_shard1_replica_t1] main]
   [junit4]   2> 2762023 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2762023 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2762023 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2762049 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1579947556631216128
   [junit4]   2> 2762052 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2762052 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2762122 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2762122 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2762123 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@53cda0c5[backuprestore_shard2_replica_n1] main]
   [junit4]   2> 2762124 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2762125 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2762158 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2762284 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1579947556877631488
   [junit4]   2> 2762261 INFO  
(searcherExecutor-2726-thread-1-processing-n:127.0.0.1:44215_solr 
x:backuprestore_shard1_replica_t1 s:shard1 c:backuprestore r:core_node2) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.c.SolrCore 
[backuprestore_shard1_replica_t1] Registered new searcher 
Searcher@1ee295cc[backuprestore_shard1_replica_t1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2762243 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 2762386 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2762387 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2762387 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2762380 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard2: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 2762389 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@4f355f43[backuprestore_shard2_replica_t1] main]
   [junit4]   2> 2762378 INFO  
(searcherExecutor-2729-thread-1-processing-n:127.0.0.1:44215_solr 
x:backuprestore_shard2_replica_n1 s:shard2 c:backuprestore r:core_node4) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard2 r:core_node4 
x:backuprestore_shard2_replica_n1] o.a.s.c.SolrCore 
[backuprestore_shard2_replica_n1] Registered new searcher 
Searcher@53cda0c5[backuprestore_shard2_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2762406 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2762406 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2762407 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3270b4b3[backuprestore_shard1_replica_p1] main]
   [junit4]   2> 2762430 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2762430 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2762433 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@47c0a926[backuprestore_shard2_replica_p1] main]
   [junit4]   2> 2762433 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2762433 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2762434 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2762442 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2762504 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.ZkController backuprestore_shard2_replica_p1 starting background 
replication from leader
   [junit4]   2> 2762506 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 2762512 INFO  
(searcherExecutor-2728-thread-1-processing-n:127.0.0.1:44215_solr 
x:backuprestore_shard2_replica_p1 s:shard2 c:backuprestore r:core_node6) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard2 r:core_node6 
x:backuprestore_shard2_replica_p1] o.a.s.c.SolrCore 
[backuprestore_shard2_replica_p1] Registered new searcher 
Searcher@47c0a926[backuprestore_shard2_replica_p1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2762516 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2762516 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2762517 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1579947557121949696
   [junit4]   2> 2762518 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 2762519 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2762519 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2762578 INFO  
(searcherExecutor-2730-thread-1-processing-n:127.0.0.1:38250_solr 
x:backuprestore_shard2_replica_t1 s:shard2 c:backuprestore r:core_node5) 
[n:127.0.0.1:38250_solr c:backuprestore s:shard2 r:core_node5 
x:backuprestore_shard2_replica_t1] o.a.s.c.SolrCore 
[backuprestore_shard2_replica_t1] Registered new searcher 
Searcher@4f355f43[backuprestore_shard2_replica_t1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2762585 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 2762585 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.ZkController backuprestore_shard1_replica_p1 starting background 
replication from leader
   [junit4]   2> 2762585 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2762585 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2762585 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:38250/solr/backuprestore_shard1_replica_n1/
   [junit4]   2> 2762585 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 
url=http://127.0.0.1:38250/solr START 
replicas=[http://127.0.0.1:44215/solr/backuprestore_shard1_replica_t1/] 
nUpdates=100
   [junit4]   2> 2762586 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 
url=http://127.0.0.1:38250/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 2762585 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 2762591 INFO  
(searcherExecutor-2731-thread-1-processing-n:127.0.0.1:38250_solr 
x:backuprestore_shard1_replica_p1 s:shard1 c:backuprestore r:core_node3) 
[n:127.0.0.1:38250_solr c:backuprestore s:shard1 r:core_node3 
x:backuprestore_shard1_replica_p1] o.a.s.c.SolrCore 
[backuprestore_shard1_replica_p1] Registered new searcher 
Searcher@3270b4b3[backuprestore_shard1_replica_p1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2762605 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 2762605 INFO  (qtp629317785-12198) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.S.Request [backuprestore_shard1_replica_t1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=16
   [junit4]   2> 2762606 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 2762606 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
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> 2762606 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 2762660 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:38250/solr/backuprestore_shard1_replica_n1/ shard1
   [junit4]   2> 2762825 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2762825 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2762826 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2762826 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2762861 INFO  (indexFetcher-2757-thread-1) 
[n:127.0.0.1:38250_solr c:backuprestore s:shard1 r:core_node3 
x:backuprestore_shard1_replica_p1] o.a.s.h.IndexFetcher Replica core_node1 is 
leader but it's state is down, skipping replication
   [junit4]   2> 2762877 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2762878 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node1&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin}
 status=0 QTime=3594
   [junit4]   2> 2762898 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2762898 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2762898 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:44215/solr/backuprestore_shard2_replica_n1/
   [junit4]   2> 2762899 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n1 
url=http://127.0.0.1:44215/solr START 
replicas=[http://127.0.0.1:38250/solr/backuprestore_shard2_replica_t1/] 
nUpdates=100
   [junit4]   2> 2762918 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n1 
url=http://127.0.0.1:44215/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 2762935 INFO  (qtp980202949-12182) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.S.Request [backuprestore_shard2_replica_t1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=1
   [junit4]   2> 2762936 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 2762936 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
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> 2762936 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 2762938 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:44215/solr/backuprestore_shard2_replica_n1/ shard2
   [junit4]   2> 2763081 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763081 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763081 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763081 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763109 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.ZkController backuprestore_shard1_replica_t1 starting background 
replication from leader
   [junit4]   2> 2763109 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 2763117 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2763120 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node4&name=backuprestore_shard2_replica_n1&action=CREATE&numShards=2&shard=shard2&wt=javabin}
 status=0 QTime=3784
   [junit4]   2> 2763133 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 2763134 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node2&name=backuprestore_shard1_replica_t1&action=CREATE&numShards=2&shard=shard1&wt=javabin}
 status=0 QTime=3577
   [junit4]   2> 2763135 INFO  (indexFetcher-2759-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.h.IndexFetcher Updated masterUrl to 
http://127.0.0.1:38250/solr/backuprestore_shard1_replica_n1/
   [junit4]   2> 2763136 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.S.Request [backuprestore_shard1_replica_n1]  webapp=/solr 
path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 2763136 INFO  (indexFetcher-2759-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 2763136 INFO  (indexFetcher-2759-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 2763136 INFO  (indexFetcher-2759-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 2763136 INFO  (indexFetcher-2759-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard1 r:core_node2 
x:backuprestore_shard1_replica_t1] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 2763137 INFO  (indexFetcher-2755-thread-1) 
[n:127.0.0.1:44215_solr c:backuprestore s:shard2 r:core_node6 
x:backuprestore_shard2_replica_p1] o.a.s.h.IndexFetcher Replica core_node4 is 
leader but it's state is down, skipping replication
   [junit4]   2> 2763243 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763243 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763244 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763244 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763610 INFO  (qtp629317785-12197) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node6 x:backuprestore_shard2_replica_p1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node6&name=backuprestore_shard2_replica_p1&action=CREATE&numShards=2&shard=shard2&wt=javabin}
 status=0 QTime=4266
   [junit4]   2> 2763621 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.ZkController backuprestore_shard2_replica_t1 starting background 
replication from leader
   [junit4]   2> 2763621 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 2763623 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 2763646 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_p1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_p1&action=CREATE&numShards=2&shard=shard1&wt=javabin}
 status=0 QTime=4089
   [junit4]   2> 2763674 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node5&name=backuprestore_shard2_replica_t1&action=CREATE&numShards=2&shard=shard2&wt=javabin}
 status=0 QTime=4118
   [junit4]   2> 2763684 INFO  (qtp980202949-12186) [n:127.0.0.1:38250_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> 2763684 INFO  
(OverseerCollectionConfigSetProcessor-98746721801142278-127.0.0.1:38250_solr-n_0000000000)
 [n:127.0.0.1:38250_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 2763755 INFO  
(zkCallback-2538-thread-1-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763755 INFO  
(zkCallback-2538-thread-2-processing-n:127.0.0.1:44215_solr) 
[n:127.0.0.1:44215_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763756 INFO  
(zkCallback-2539-thread-2-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2763756 INFO  
(zkCallback-2539-thread-1-processing-n:127.0.0.1:38250_solr) 
[n:127.0.0.1:38250_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/backuprestore/state.json] for collection [backuprestore] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 2764684 INFO  (qtp980202949-12186) [n:127.0.0.1:38250_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={pullReplicas=1&replicationFactor=1&property.customKey=customValue&collection.configName=conf1&maxShardsPerNode=6&name=backuprestore&nrtReplicas=1&action=CREATE&numShards=2&tlogReplicas=1&wt=javabin&version=2}
 status=0 QTime=6177
   [junit4]   2> 2764939 INFO  (qtp629317785-12200) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_t1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:38250/solr/backuprestore_shard1_replica_n1/&wt=javabin&version=2}{add=[0
 (1579947559546257408), 1 (1579947559563034624), 4 (1579947559563034625), 8 
(1579947559563034626), 10 (1579947559563034627), 11 (1579947559563034628), 12 
(1579947559563034629), 13 (1579947559563034630), 14 (1579947559563034631), 15 
(1579947559563034632), ... (41 adds)]} 0 92
   [junit4]   2> 2764939 INFO  (qtp980202949-12184) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 
(1579947559546257408), 1 (1579947559563034624), 4 (1579947559563034625), 8 
(1579947559563034626), 10 (1579947559563034627), 11 (1579947559563034628), 12 
(1579947559563034629), 13 (1579947559563034630), 14 (1579947559563034631), 15 
(1579947559563034632), ... (41 adds)]} 0 170
   [junit4]   2> 2764975 INFO  (qtp980202949-12182) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_t1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:44215/solr/backuprestore_shard2_replica_n1/&wt=javabin&version=2}{add=[2
 (1579947559500120064), 3 (1579947559678377984), 5 (1579947559678377985), 6 
(1579947559678377986), 7 (1579947559678377987), 9 (1579947559678377988), 17 
(1579947559678377989), 18 (1579947559678377990), 19 (1579947559678377991), 21 
(1579947559678377992), ... (29 adds)]} 0 18
   [junit4]   2> 2764975 INFO  (qtp629317785-12193) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 
(1579947559500120064), 3 (1579947559678377984), 5 (1579947559678377985), 6 
(1579947559678377986), 7 (1579947559678377987), 9 (1579947559678377988), 17 
(1579947559678377989), 18 (1579947559678377990), 19 (1579947559678377991), 21 
(1579947559678377992), ... (29 adds)]} 0 218
   [junit4]   2> 2765063 INFO  (qtp980202949-12189) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1579947559791624192,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2765077 INFO  (qtp980202949-12188) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard2 r:core_node5 x:backuprestore_shard2_replica_t1] 
o.a.s.u.TestInjection Start waiting for replica in sync with leader
   [junit4]   2> 2765085 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1579947559814692864,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2765085 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@63bef3df 
commitCommandVersion:1579947559814692864
   [junit4]   2> 2765078 INFO  (qtp629317785-12194) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard1 r:core_node2 x:backuprestore_shard1_replica_t1] 
o.a.s.u.TestInjection Start waiting for replica in sync with leader
   [junit4]   2> 2765166 INFO  (qtp980202949-12189) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@2256db80 
commitCommandVersion:1579947559791624192
   [junit4]   2> 2765167 INFO  (qtp629317785-12199) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.c.S.Request [backuprestore_shard2_replica_n1]  webapp=/solr 
path=/replication params={qt=/replication&wt=javabin&version=2&command=details} 
status=0 QTime=66
   [junit4]   2> 2765228 INFO  (qtp980202949-12183) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.c.S.Request [backuprestore_shard1_replica_n1]  webapp=/solr 
path=/replication params={qt=/replication&wt=javabin&version=2&command=details} 
status=0 QTime=0
   [junit4]   2> 2765249 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6ca1d912[backuprestore_shard2_replica_n1] main]
   [junit4]   2> 2765249 INFO  (qtp629317785-12196) [n:127.0.0.1:44215_solr 
c:backuprestore s:shard2 r:core_node4 x:backuprestore_shard2_replica_n1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2765265 INFO  (qtp980202949-12189) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1a58e549[backuprestore_shard1_replica_n1] main]
   [junit4]   2> 2765265 INFO  (qtp980202949-12189) [n:127.0.0.1:38250_solr 
c:backuprestore s:shard1 r:core_node1 x:backuprestore_shard1_replica_n1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2765266 INFO  (searcherExecutor-2727-

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

]   2>  12      /solr/collections/movereplicatest_coll2/state.json
   [junit4]   2>        3       /solr/clusterstate.json
   [junit4]   2>        3       /solr/clusterprops.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        3       /solr/live_nodes
   [junit4]   2>        3       /solr/collections
   [junit4]   2> 
   [junit4]   2> 5078802 WARN  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
   [junit4]   2> 5079187 INFO  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 5079188 WARN  (1169012686@qtp-2122844304-1 - Acceptor0 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34764) [    ] 
o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false. Rechecking.
   [junit4]   2> 5079188 WARN  (1169012686@qtp-2122844304-1 - Acceptor0 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34764) [    ] 
o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false
   [junit4]   2> 5079306 WARN  (DataNode: 
[[[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data3/,
 
[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data4/]]
  heartbeating to lucene2-us-west.apache.org/127.0.0.1:35707) [    ] 
o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager 
interrupted
   [junit4]   2> 5079306 WARN  (DataNode: 
[[[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data3/,
 
[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data4/]]
  heartbeating to lucene2-us-west.apache.org/127.0.0.1:35707) [    ] 
o.a.h.h.s.d.DataNode Ending block pool service for: Block pool 
BP-968873963-127.0.0.1-1506757684009 (Datanode Uuid 
a88226f1-6187-42ee-807b-19a6faa77654) service to 
lucene2-us-west.apache.org/127.0.0.1:35707
   [junit4]   2> 5079360 WARN  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
   [junit4]   2> 5079634 INFO  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.m.log Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 5079652 WARN  (1451073941@qtp-610464650-1 - Acceptor0 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:38605) [    ] 
o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false. Rechecking.
   [junit4]   2> 5079653 WARN  (1451073941@qtp-610464650-1 - Acceptor0 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:38605) [    ] 
o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false
   [junit4]   2> 5079743 WARN  (DataNode: 
[[[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data1/,
 
[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data2/]]
  heartbeating to lucene2-us-west.apache.org/127.0.0.1:35707) [    ] 
o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager 
interrupted
   [junit4]   2> 5079743 WARN  (DataNode: 
[[[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data1/,
 
[DISK]file:/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001/tempDir-002/hdfsBaseDir/data/data2/]]
  heartbeating to lucene2-us-west.apache.org/127.0.0.1:35707) [    ] 
o.a.h.h.s.d.DataNode Ending block pool service for: Block pool 
BP-968873963-127.0.0.1-1506757684009 (Datanode Uuid 
0dbc0358-f0d4-440c-818c-3b1bac930c8d) service to 
lucene2-us-west.apache.org/127.0.0.1:35707
   [junit4]   2> 5079892 INFO  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.m.log Stopped 
HttpServer2$selectchannelconnectorwithsafestar...@lucene2-us-west.apache.org:0
   [junit4]   2> 5079926 WARN  (1469227894@qtp-171620703-1 - Acceptor0 
HttpServer2$selectchannelconnectorwithsafestar...@lucene2-us-west.apache.org:34095)
 [    ] o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false. Rechecking.
   [junit4]   2> 5079926 WARN  (1469227894@qtp-171620703-1 - Acceptor0 
HttpServer2$selectchannelconnectorwithsafestar...@lucene2-us-west.apache.org:34095)
 [    ] o.a.h.h.HttpServer2 HttpServer Acceptor: isRunning is false
   [junit4]   2> 5080184 INFO  
(SUITE-MoveReplicaHDFSUlogDirTest-seed#[F02F5FCB4A4B405A]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:43287 43287
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.0/solr/build/solr-core/test/J1/temp/solr.cloud.MoveReplicaHDFSUlogDirTest_F02F5FCB4A4B405A-001
   [junit4]   2> Sep 30, 2017 7:48:44 AM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 34 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene70, 
sim=RandomSimilarity(queryNorm=false): {}, locale=pt-PT, 
timezone=America/Argentina/Salta
   [junit4]   2> NOTE: Linux 4.4.0-83-generic amd64/Oracle Corporation 
1.8.0_144 (64-bit)/cpus=4,threads=2,free=247702176,total=521666560
   [junit4]   2> NOTE: All tests run in this JVM: [EnumFieldTest, 
CursorMarkTest, DistribDocExpirationUpdateProcessorTest, CdcrBootstrapTest, 
TestXmlQParserPlugin, TestPerFieldSimilarityWithDefaultOverride, 
CdcrRequestHandlerTest, TestCollapseQParserPlugin, TestConfigSetProperties, 
ConfigureRecoveryStrategyTest, TestFuzzyAnalyzedSuggestions, TestCryptoKeys, 
HdfsDirectoryTest, UpdateRequestProcessorFactoryTest, TestHdfsUpdateLog, 
OverseerStatusTest, TestCharFilters, TestSizeLimitedDistributedMap, 
TestRandomFlRTGCloud, DistributedTermsComponentTest, 
TestRandomCollapseQParserPlugin, BasicFunctionalityTest, 
PKIAuthenticationIntegrationTest, TermVectorComponentTest, 
CloudExitableDirectoryReaderTest, TestCoreContainer, TestHashPartitioner, 
FileBasedSpellCheckerTest, HdfsBasicDistributedZk2Test, 
TestAuthenticationFramework, TestValueSourceCache, TestCloudRecovery, 
TestQueryTypes, TestSystemIdResolver, ImplicitSnitchTest, TestBulkSchemaAPI, 
RankQueryTest, TestElisionMultitermQuery, TestExportWriter, 
DistributedExpandComponentTest, DistributedMLTComponentTest, TestUpdate, 
TestManagedSchemaAPI, TestLegacyFieldCache, PropertiesRequestHandlerTest, 
TestStressLiveNodes, TestSolrIndexConfig, ScriptEngineTest, DOMUtilTest, 
CacheHeaderTest, HdfsRecoverLeaseTest, TestCollationFieldDocValues, 
VMParamsZkACLAndCredentialsProvidersTest, HttpSolrCallGetCoreTest, 
TestImpersonationWithHadoopAuth, TestUninvertingReader, 
DistributedFacetPivotLongTailTest, StatsReloadRaceTest, 
PreAnalyzedUpdateProcessorTest, SolrGraphiteReporterTest, HttpPartitionTest, 
SampleTest, DistanceFunctionTest, AssignTest, CurrencyFieldTypeTest, 
TestLeaderElectionWithEmptyReplica, BigEndianAscendingWordSerializerTest, 
TestCloudManagedSchema, ClusterStateUpdateTest, TestMultiWordSynonyms, 
DistributedSuggestComponentTest, LoggingHandlerTest, 
ClassificationUpdateProcessorIntegrationTest, UpdateLogTest, ZkCLITest, 
HdfsChaosMonkeySafeLeaderTest, TestLRUCache, PrimUtilsTest, 
SubstringBytesRefFilterTest, TestLegacyNumericRangeQueryBuilder, 
TestReplicaProperties, TestXIncludeConfig, BlockJoinFacetSimpleTest, 
TestTolerantUpdateProcessorRandomCloud, TestJavabinTupleStreamParser, 
SparseHLLTest, SuggesterTSTTest, TestCursorMarkWithoutUniqueKey, 
TestStressVersions, TestLocalFSCloudBackupRestore, TestBlobHandler, 
TestCustomSort, TestSubQueryTransformer, TestSchemaManager, 
TestCloudJSONFacetJoinDomain, ConvertedLegacyTest, MetricsConfigTest, 
OverseerCollectionConfigSetProcessorTest, DocValuesMultiTest, 
TestPartialUpdateDeduplication, TestFieldCacheSortRandom, 
TestMultiValuedNumericRangeQuery, TestReloadAndDeleteDocs, CdcrUpdateLogTest, 
TestDownShardTolerantSearch, TestSweetSpotSimilarityFactory, DistanceUnitsTest, 
HdfsSyncSliceTest, SystemInfoHandlerTest, TestManagedStopFilterFactory, 
TestDistributedGrouping, SolrMetricReporterTest, TestLRUStatsCache, 
TestNestedDocsSort, TestEmbeddedSolrServerConstructors, 
SharedFSAutoReplicaFailoverTest, TestSolrCloudWithSecureImpersonation, 
MigrateRouteKeyTest, HighlighterTest, ShardRoutingCustomTest, 
TestDistributedSearch, DistributedSpellCheckComponentTest, ZkControllerTest, 
HardAutoCommitTest, TestRangeQuery, TestLazyCores, SolrIndexSplitterTest, 
TestCoreDiscovery, AnalysisAfterCoreReloadTest, SuggesterFSTTest, 
SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, 
PrimitiveFieldTypeTest, PathHierarchyTokenizerFactoryTest, 
FastVectorHighlighterTest, TestCSVResponseWriter, QueryParsingTest, 
CSVRequestHandlerTest, TestComponentsName, TestLFUCache, TestRTGBase, 
TestHighlightDedupGrouping, TestTolerantSearch, TestLuceneIndexBackCompat, 
BaseCdcrDistributedZkTest, CdcrVersionReplicationTest, CollectionReloadTest, 
CollectionTooManyReplicasTest, DeleteInactiveReplicaTest, DeleteReplicaTest, 
DocValuesNotIndexedTest, LeaderInitiatedRecoveryOnShardRestartTest, 
MoveReplicaHDFSUlogDirTest]
   [junit4] Completed [512/730 (3!)] on J1 in 51.77s, 1 test, 1 error <<< 
FAILURES!

[...truncated 44213 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to