You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/05/26 09:43:45 UTC
[JENKINS-EA] Lucene-Solr-master-Linux (64bit/jdk-9-ea+168) - Build
# 19713 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/19713/
Java: 64bit/jdk-9-ea+168 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.TestLocalFSCloudBackupRestore.test
Error Message:
expected:<COMPLETED> but was:<FAILED>
Stack Trace:
java.lang.AssertionError: expected:<COMPLETED> but was:<FAILED>
at __randomizedtesting.SeedInfo.seed([1F83D253A1D8B6E4:97D7ED890F24DB1C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:271)
at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:135)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:563)
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 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.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12586 lines...]
[junit4] Suite: org.apache.solr.cloud.TestLocalFSCloudBackupRestore
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/init-core-data-001
[junit4] 2> 1702058 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 1702058 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 1702059 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001
[junit4] 2> 1702059 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1702059 INFO (Thread-3695) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1702059 INFO (Thread-3695) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1702060 ERROR (Thread-3695) [ ] 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> 1702159 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34097
[junit4] 2> 1702163 INFO (jetty-launcher-2821-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1702164 INFO (jetty-launcher-2821-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1702165 INFO (jetty-launcher-2821-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6a7e0d98{/solr,null,AVAILABLE}
[junit4] 2> 1702165 INFO (jetty-launcher-2821-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@442cfdbb{/solr,null,AVAILABLE}
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2538489b{HTTP/1.1,[http/1.1]}{127.0.0.1:43865}
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@245fe81b{HTTP/1.1,[http/1.1]}{127.0.0.1:36291}
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-1) [ ] o.e.j.s.Server Started @1704405ms
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-2) [ ] o.e.j.s.Server Started @1704406ms
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43865}
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36291}
[junit4] 2> 1702166 ERROR (jetty-launcher-2821-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1702166 ERROR (jetty-launcher-2821-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1702166 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1702167 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1702167 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1702167 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1702167 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-05-26T09:28:24.295195Z
[junit4] 2> 1702167 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-05-26T09:28:24.295262Z
[junit4] 2> 1702168 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1702169 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1702174 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34097/solr
[junit4] 2> 1702174 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34097/solr
[junit4] 2> 1702176 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15c4415e37b0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1702184 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1702184 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1702185 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43865_solr
[junit4] 2> 1702185 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36291_solr
[junit4] 2> 1702185 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98028152696799237-127.0.0.1:43865_solr-n_0000000000) starting
[junit4] 2> 1702185 INFO (zkCallback-2832-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1702186 INFO (zkCallback-2833-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1702189 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43865_solr
[junit4] 2> 1702190 INFO (zkCallback-2833-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1702190 INFO (zkCallback-2832-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1702223 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702223 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702225 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702225 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702225 INFO (jetty-launcher-2821-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/.
[junit4] 2> 1702225 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702225 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1702226 INFO (jetty-launcher-2821-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/.
[junit4] 2> 1702242 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1702243 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34097/solr ready
[junit4] 2> 1702247 INFO (TEST-TestLocalFSCloudBackupRestore.test-seed#[1F83D253A1D8B6E4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 1702249 INFO (qtp1345914338-17203) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf1&router.name=implicit&version=2&pullReplicas=1&shards=shard1,shard2&property.customKey=customValue&maxShardsPerNode=3&router.field=shard_s&name=backuprestore&nrtReplicas=2&action=CREATE&tlogReplicas=0&wt=javabin and sendToOCPQueue=true
[junit4] 2> 1702250 INFO (OverseerThreadFactory-7963-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection backuprestore
[junit4] 2> 1702250 WARN (OverseerThreadFactory-7963-thread-1) [ ] 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> 1702353 INFO (qtp1345914338-17207) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_n2&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1702353 INFO (qtp1345914338-17207) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1702353 INFO (qtp1345914338-17197) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_n1&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1702354 INFO (qtp1688637874-17200) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1702354 INFO (qtp1345914338-17199) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_p1&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 1702355 INFO (qtp1688637874-17200) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1702355 INFO (qtp1688637874-17198) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_p1&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 1702355 INFO (qtp1688637874-17196) [ ] o.a.s.h.a.CoreAdminOperation core create command property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_n2&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1702460 INFO (zkCallback-2832-thread-1) [ ] 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> 1702460 INFO (zkCallback-2833-thread-2) [ ] 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> 1703359 INFO (qtp1688637874-17200) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703371 INFO (qtp1345914338-17207) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703371 INFO (qtp1345914338-17197) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703374 INFO (qtp1688637874-17196) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703375 INFO (qtp1688637874-17198) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703378 INFO (qtp1345914338-17197) [ ] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n1] Schema name=minimal
[junit4] 2> 1703378 INFO (qtp1688637874-17198) [ ] o.a.s.s.IndexSchema [backuprestore_shard1_replica_p1] Schema name=minimal
[junit4] 2> 1703378 INFO (qtp1345914338-17207) [ ] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n2] Schema name=minimal
[junit4] 2> 1703378 INFO (qtp1688637874-17200) [ ] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n1] Schema name=minimal
[junit4] 2> 1703380 INFO (qtp1345914338-17207) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703380 INFO (qtp1688637874-17198) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703380 INFO (qtp1688637874-17198) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_p1' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703380 INFO (qtp1688637874-17198) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.core.backuprestore.shard1.replica_p1' (registry 'solr.core.backuprestore.shard1.replica_p1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703380 INFO (qtp1688637874-17200) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703380 INFO (qtp1688637874-17200) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n1' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703380 INFO (qtp1688637874-17198) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703380 INFO (qtp1688637874-17198) [ ] o.a.s.c.SolrCore [[backuprestore_shard1_replica_p1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/backuprestore_shard1_replica_p1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/./backuprestore_shard1_replica_p1/data/]
[junit4] 2> 1703381 INFO (qtp1688637874-17200) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.core.backuprestore.shard1.replica_n1' (registry 'solr.core.backuprestore.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703381 INFO (qtp1688637874-17200) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703381 INFO (qtp1688637874-17200) [ ] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/backuprestore_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/./backuprestore_shard1_replica_n1/data/]
[junit4] 2> 1703378 INFO (qtp1688637874-17196) [ ] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n2] Schema name=minimal
[junit4] 2> 1703380 INFO (qtp1345914338-17207) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n2' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703382 INFO (qtp1345914338-17207) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.core.backuprestore.shard1.replica_n2' (registry 'solr.core.backuprestore.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703382 INFO (qtp1345914338-17207) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703382 INFO (qtp1345914338-17207) [ ] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/backuprestore_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/./backuprestore_shard1_replica_n2/data/]
[junit4] 2> 1703380 INFO (qtp1345914338-17197) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703393 INFO (qtp1688637874-17196) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703393 INFO (qtp1688637874-17196) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n2' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703394 INFO (qtp1688637874-17196) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36291.solr.core.backuprestore.shard2.replica_n2' (registry 'solr.core.backuprestore.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703394 INFO (qtp1688637874-17196) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703394 INFO (qtp1688637874-17196) [ ] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/backuprestore_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node2/./backuprestore_shard2_replica_n2/data/]
[junit4] 2> 1703397 INFO (qtp1345914338-17197) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n1' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703397 INFO (qtp1345914338-17197) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.core.backuprestore.shard2.replica_n1' (registry 'solr.core.backuprestore.shard2.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703397 INFO (qtp1345914338-17197) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703397 INFO (qtp1345914338-17197) [ ] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/backuprestore_shard2_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/./backuprestore_shard2_replica_n1/data/]
[junit4] 2> 1703407 INFO (qtp1345914338-17199) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1703412 INFO (qtp1345914338-17199) [ ] o.a.s.s.IndexSchema [backuprestore_shard2_replica_p1] Schema name=minimal
[junit4] 2> 1703413 INFO (qtp1345914338-17199) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1703413 INFO (qtp1345914338-17199) [ ] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_p1' using configuration from collection backuprestore, trusted=true
[junit4] 2> 1703413 INFO (qtp1345914338-17199) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43865.solr.core.backuprestore.shard2.replica_p1' (registry 'solr.core.backuprestore.shard2.replica_p1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26049fc4
[junit4] 2> 1703414 INFO (qtp1345914338-17199) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1703414 INFO (qtp1345914338-17199) [ ] o.a.s.c.SolrCore [[backuprestore_shard2_replica_p1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/backuprestore_shard2_replica_p1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/tempDir-001/node1/./backuprestore_shard2_replica_p1/data/]
[junit4] 2> 1703429 INFO (qtp1688637874-17198) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703429 INFO (qtp1688637874-17198) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703447 INFO (qtp1688637874-17198) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4ee1a4ee[backuprestore_shard1_replica_p1] main]
[junit4] 2> 1703448 INFO (qtp1688637874-17198) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703448 INFO (qtp1688637874-17198) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703449 INFO (qtp1688637874-17198) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703449 INFO (qtp1688637874-17198) [ ] o.a.s.c.ZkController backuprestore_shard1_replica_p1 starting background replication from leader
[junit4] 2> 1703449 INFO (qtp1688637874-17198) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 1703449 INFO (searcherExecutor-7968-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_p1] Registered new searcher Searcher@4ee1a4ee[backuprestore_shard1_replica_p1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703450 INFO (qtp1688637874-17198) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 1703450 WARN (qtp1688637874-17198) [ ] o.a.s.h.ReplicationHandler SolrCloud is enabled for core backuprestore_shard1_replica_p1 but so is old-style replication. Make sure you intend this behavior, it usually indicates a mis-configuration. Master setting is false and slave setting is true
[junit4] 2> 1703455 INFO (qtp1688637874-17196) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1703455 INFO (qtp1688637874-17200) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1703455 INFO (qtp1688637874-17200) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1703455 INFO (qtp1688637874-17196) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1703456 INFO (qtp1688637874-17200) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703456 INFO (qtp1688637874-17200) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703457 INFO (qtp1688637874-17200) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a081692[backuprestore_shard1_replica_n1] main]
[junit4] 2> 1703457 INFO (qtp1688637874-17196) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703458 INFO (qtp1688637874-17196) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703458 INFO (qtp1688637874-17200) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703458 INFO (qtp1688637874-17200) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703459 INFO (qtp1688637874-17200) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703459 INFO (qtp1688637874-17196) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3089a48a[backuprestore_shard2_replica_n2] main]
[junit4] 2> 1703459 INFO (qtp1688637874-17196) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703459 INFO (qtp1688637874-17196) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703459 INFO (searcherExecutor-7969-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n1] Registered new searcher Searcher@7a081692[backuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703459 INFO (qtp1688637874-17200) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1568450444616794112
[junit4] 2> 1703460 INFO (qtp1688637874-17196) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703460 INFO (searcherExecutor-7971-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n2] Registered new searcher Searcher@3089a48a[backuprestore_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703460 INFO (qtp1688637874-17196) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1568450444617842688
[junit4] 2> 1703462 INFO (qtp1688637874-17200) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1703463 INFO (qtp1688637874-17196) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1703469 INFO (qtp1345914338-17207) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1703469 INFO (qtp1345914338-17207) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1703470 INFO (qtp1345914338-17207) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703470 INFO (qtp1345914338-17207) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703471 INFO (qtp1345914338-17207) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@274238[backuprestore_shard1_replica_n2] main]
[junit4] 2> 1703471 INFO (qtp1345914338-17207) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703471 INFO (qtp1345914338-17207) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703472 INFO (qtp1345914338-17207) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703472 INFO (searcherExecutor-7970-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n2] Registered new searcher Searcher@274238[backuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703472 INFO (qtp1345914338-17207) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1568450444630425600
[junit4] 2> 1703484 INFO (qtp1345914338-17199) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703484 INFO (qtp1345914338-17199) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703485 INFO (qtp1345914338-17199) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6117c723[backuprestore_shard2_replica_p1] main]
[junit4] 2> 1703486 INFO (qtp1345914338-17199) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703486 INFO (qtp1345914338-17199) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703487 INFO (qtp1345914338-17199) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703487 INFO (qtp1345914338-17197) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1703487 INFO (qtp1345914338-17197) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1703487 INFO (searcherExecutor-7973-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_p1] Registered new searcher Searcher@6117c723[backuprestore_shard2_replica_p1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703488 INFO (qtp1345914338-17199) [ ] o.a.s.c.ZkController backuprestore_shard2_replica_p1 starting background replication from leader
[junit4] 2> 1703488 INFO (qtp1345914338-17199) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 1703488 INFO (qtp1345914338-17197) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1703488 INFO (qtp1345914338-17197) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1703488 INFO (qtp1345914338-17199) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 1703488 WARN (qtp1345914338-17199) [ ] o.a.s.h.ReplicationHandler SolrCloud is enabled for core backuprestore_shard2_replica_p1 but so is old-style replication. Make sure you intend this behavior, it usually indicates a mis-configuration. Master setting is false and slave setting is true
[junit4] 2> 1703489 INFO (qtp1345914338-17197) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4967672d[backuprestore_shard2_replica_n1] main]
[junit4] 2> 1703489 INFO (qtp1345914338-17197) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1703490 INFO (qtp1345914338-17197) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1703490 INFO (qtp1345914338-17197) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1703490 INFO (searcherExecutor-7972-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n1] Registered new searcher Searcher@4967672d[backuprestore_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1703490 INFO (qtp1345914338-17197) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1568450444649299968
[junit4] 2> 1703564 INFO (zkCallback-2833-thread-2) [ ] 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> 1703564 INFO (zkCallback-2832-thread-1) [ ] 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> 1703963 INFO (qtp1688637874-17200) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1703963 INFO (qtp1688637874-17200) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1703963 INFO (qtp1688637874-17200) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/
[junit4] 2> 1703963 INFO (qtp1688637874-17196) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1703963 INFO (qtp1688637874-17196) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1703963 INFO (qtp1688637874-17196) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36291/solr/backuprestore_shard2_replica_n2/
[junit4] 2> 1703963 INFO (qtp1688637874-17200) [ ] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 url=http://127.0.0.1:36291/solr START replicas=[http://127.0.0.1:43865/solr/backuprestore_shard1_replica_n2/] nUpdates=100
[junit4] 2> 1703964 INFO (qtp1688637874-17200) [ ] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 url=http://127.0.0.1:36291/solr DONE. We have no versions. sync failed.
[junit4] 2> 1703964 INFO (qtp1688637874-17196) [ ] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n2 url=http://127.0.0.1:36291/solr START replicas=[http://127.0.0.1:43865/solr/backuprestore_shard2_replica_n1/] nUpdates=100
[junit4] 2> 1703964 INFO (qtp1688637874-17196) [ ] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n2 url=http://127.0.0.1:36291/solr DONE. We have no versions. sync failed.
[junit4] 2> 1703965 INFO (qtp1345914338-17194) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1703965 INFO (qtp1688637874-17200) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1703965 INFO (qtp1688637874-17200) [ ] 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> 1703965 INFO (qtp1688637874-17200) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1703965 INFO (qtp1345914338-17194) [ ] o.a.s.c.S.Request [backuprestore_shard2_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1703966 INFO (qtp1688637874-17196) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1703966 INFO (qtp1688637874-17196) [ ] 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> 1703966 INFO (qtp1688637874-17196) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1703968 INFO (qtp1688637874-17200) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/ shard1
[junit4] 2> 1703968 INFO (qtp1688637874-17196) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36291/solr/backuprestore_shard2_replica_n2/ shard2
[junit4] 2> 1704071 INFO (zkCallback-2833-thread-2) [ ] 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> 1704071 INFO (zkCallback-2832-thread-1) [ ] 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> 1704102 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Replica core_node4 is leader but it's state is down, skipping replication
[junit4] 2> 1704119 INFO (qtp1688637874-17200) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1704119 INFO (qtp1688637874-17196) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1704121 INFO (qtp1688637874-17200) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1766
[junit4] 2> 1704121 INFO (qtp1688637874-17196) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_n2&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1765
[junit4] 2> 1704223 INFO (zkCallback-2833-thread-2) [ ] 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> 1704223 INFO (zkCallback-2832-thread-1) [ ] 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> 1704453 INFO (qtp1688637874-17198) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_p1&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2097
[junit4] 2> 1704476 INFO (qtp1345914338-17207) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard1_replica_n2&action=CREATE&numShards=2&collection=backuprestore&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2123
[junit4] 2> 1704491 INFO (qtp1345914338-17199) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_p1&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=PULL} status=0 QTime=2136
[junit4] 2> 1704494 INFO (qtp1345914338-17197) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.customKey=customValue&qt=/admin/cores&collection.configName=conf1&newCollection=true&name=backuprestore_shard2_replica_n1&action=CREATE&numShards=2&collection=backuprestore&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2140
[junit4] 2> 1704496 INFO (qtp1345914338-17203) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1704596 INFO (zkCallback-2832-thread-1) [ ] 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> 1704596 INFO (zkCallback-2833-thread-2) [ ] 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> 1705028 INFO (indexFetcher-7999-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:36291/solr/backuprestore_shard2_replica_n2/
[junit4] 2> 1705029 INFO (qtp1688637874-17263) [ ] o.a.s.c.S.Request [backuprestore_shard2_replica_n2] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 1705029 INFO (indexFetcher-7999-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 1705029 INFO (indexFetcher-7999-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 1705029 INFO (indexFetcher-7999-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1705030 INFO (indexFetcher-7999-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 1705496 INFO (qtp1345914338-17203) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf1&router.name=implicit&version=2&pullReplicas=1&shards=shard1,shard2&property.customKey=customValue&maxShardsPerNode=3&router.field=shard_s&name=backuprestore&nrtReplicas=2&action=CREATE&tlogReplicas=0&wt=javabin} status=0 QTime=3247
[junit4] 2> 1705501 INFO (qtp1345914338-17261) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&wt=javabin&version=2}{add=[0 (1568450446754840576), 2 (1568450446755889152), 4 (1568450446756937728), 5 (1568450446756937729), 7 (1568450446756937730), 8 (1568450446756937731), 10 (1568450446756937732)]} 0 1
[junit4] 2> 1705503 INFO (qtp1345914338-17281) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard2_replica_n2/&wt=javabin&version=2}{add=[1 (1568450446756937728), 3 (1568450446757986304), 6 (1568450446757986305), 9 (1568450446757986306), 11 (1568450446757986307), 12 (1568450446757986308), 13 (1568450446757986309), 14 (1568450446757986310), 15 (1568450446759034880), 16 (1568450446759034881), ... (14 adds)]} 0 1
[junit4] 2> 1705503 INFO (qtp1688637874-17202) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&wt=javabin&version=2}{add=[1 (1568450446756937728), 3 (1568450446757986304), 6 (1568450446757986305), 9 (1568450446757986306), 11 (1568450446757986307), 12 (1568450446757986308), 13 (1568450446757986309), 14 (1568450446757986310), 15 (1568450446759034880), 16 (1568450446759034881), ... (14 adds)]} 0 2
[junit4] 2> 1705503 INFO (qtp1688637874-17196) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1568450446754840576), 1, 2 (1568450446755889152), 3, 4 (1568450446756937728), 5 (1568450446756937729), 6, 7 (1568450446756937730), 8 (1568450446756937731), 9, ... (21 adds)]} 0 5
[junit4] 2> 1705504 INFO (qtp1345914338-17194) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1568450446761132032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1705504 INFO (qtp1345914338-17194) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@75a35a09 commitCommandVersion:1568450446761132032
[junit4] 2> 1705504 INFO (qtp1688637874-17208) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1568450446761132032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1705504 INFO (qtp1688637874-17208) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@f5785b0 commitCommandVersion:1568450446761132032
[junit4] 2> 1705504 INFO (qtp1345914338-17199) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1568450446761132032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1705504 INFO (qtp1688637874-17202) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1568450446761132032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1705504 INFO (qtp1345914338-17199) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3d6ae461 commitCommandVersion:1568450446761132032
[junit4] 2> 1705505 INFO (qtp1688637874-17202) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3551492c commitCommandVersion:1568450446761132032
[junit4] 2> 1705506 INFO (qtp1345914338-17199) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4caa9711[backuprestore_shard2_replica_n1] main]
[junit4] 2> 1705506 INFO (qtp1688637874-17208) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4b8b2704[backuprestore_shard1_replica_n1] main]
[junit4] 2> 1705506 INFO (qtp1688637874-17202) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3bcf88c2[backuprestore_shard2_replica_n2] main]
[junit4] 2> 1705506 INFO (qtp1345914338-17194) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2a21c08c[backuprestore_shard1_replica_n2] main]
[junit4] 2> 1705506 INFO (qtp1345914338-17199) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1705506 INFO (qtp1688637874-17208) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1705506 INFO (qtp1688637874-17202) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1705506 INFO (qtp1345914338-17194) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1705507 INFO (searcherExecutor-7972-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n1] Registered new searcher Searcher@4caa9711[backuprestore_shard2_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C14)))}
[junit4] 2> 1705507 INFO (searcherExecutor-7969-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n1] Registered new searcher Searcher@4b8b2704[backuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C7)))}
[junit4] 2> 1705507 INFO (qtp1345914338-17199) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 1705507 INFO (qtp1688637874-17208) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 1705507 INFO (searcherExecutor-7971-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n2] Registered new searcher Searcher@3bcf88c2[backuprestore_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C14)))}
[junit4] 2> 1705507 INFO (searcherExecutor-7970-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n2] Registered new searcher Searcher@2a21c08c[backuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C7)))}
[junit4] 2> 1705508 INFO (qtp1688637874-17202) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 1705508 INFO (qtp1345914338-17194) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 1705508 INFO (qtp1688637874-17263) [ ] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=backuprestore:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 4
[junit4] 2> 1705509 INFO (qtp1688637874-17198) [ ] o.a.s.c.S.Request [backuprestore_shard2_replica_n2] webapp=/solr path=/select params={q=*:*&distrib=false&wt=javabin&version=2} hits=14 status=0 QTime=0
[junit4] 2> 1705510 INFO (qtp1688637874-17209) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&distrib=false&wt=javabin&version=2} hits=7 status=0 QTime=0
[junit4] 2> 1705510 INFO (TEST-TestLocalFSCloudBackupRestore.test-seed#[1F83D253A1D8B6E4]) [ ] o.a.s.c.AbstractCloudBackupRestoreTestCase Triggering Backup command
[junit4] 2> 1705512 INFO (qtp1345914338-17205) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :backup with params name=mytestbackup&action=BACKUP&location=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001&collection=backuprestore&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1705515 INFO (OverseerCollectionConfigSetProcessor-98028152696799237-127.0.0.1:43865_solr-n_0000000000) [ ] 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> 1705518 INFO (OverseerThreadFactory-7963-thread-2) [ ] o.a.s.c.BackupCmd Starting backup of collection=backuprestore with backupName=mytestbackup at location=file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup
[junit4] 2> 1705519 INFO (qtp1688637874-17206) [ ] o.a.s.h.SnapShooter Creating backup snapshot shard1 at file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup
[junit4] 2> 1705519 INFO (qtp1688637874-17208) [ ] o.a.s.h.SnapShooter Creating backup snapshot shard2 at file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup
[junit4] 2> 1705521 INFO (qtp1688637874-17206) [ ] o.a.s.h.SnapShooter Done creating backup snapshot: shard1 at file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup
[junit4] 2> 1705521 INFO (qtp1688637874-17208) [ ] o.a.s.h.SnapShooter Done creating backup snapshot: shard2 at file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup
[junit4] 2> 1705521 INFO (qtp1688637874-17206) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=backuprestore_shard1_replica_n1&qt=/admin/cores&name=shard1&action=BACKUPCORE&location=file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1705522 INFO (qtp1688637874-17208) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=backuprestore_shard2_replica_n2&qt=/admin/cores&name=shard2&action=BACKUPCORE&location=file:///home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001/mytestbackup&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1705522 INFO (OverseerThreadFactory-7963-thread-2) [ ] o.a.s.c.BackupCmd Starting to backup ZK data for backupName=mytestbackup
[junit4] 2> 1705524 INFO (OverseerThreadFactory-7963-thread-2) [ ] o.a.s.c.b.BackupManager Writing file schema.xml
[junit4] 2> 1705525 INFO (OverseerThreadFactory-7963-thread-2) [ ] o.a.s.c.b.BackupManager Writing file solrconfig.xml
[junit4] 2> 1705526 INFO (OverseerThreadFactory-7963-thread-2) [ ] o.a.s.c.BackupCmd Completed backing up ZK data for backupName=mytestbackup
[junit4] 2> 1705527 INFO (qtp1345914338-17205) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=mytestbackup&action=BACKUP&location=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001&collection=backuprestore&wt=javabin&version=2} status=0 QTime=15
[junit4] 2> 1705528 INFO (TEST-TestLocalFSCloudBackupRestore.test-seed#[1F83D253A1D8B6E4]) [ ] o.a.s.c.AbstractCloudBackupRestoreTestCase Triggering Restore command
[junit4] 2> 1705529 INFO (qtp1345914338-17203) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :restore with params async=06aa7c4c-b351-4ef2-a702-ec37a61485a1&property.customKey=customVal&maxShardsPerNode=4&name=mytestbackup&action=RESTORE&location=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001&createNodeSet=127.0.0.1:36291_solr&collection=backuprestore_restored&createNodeSet.shuffle=true&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1705531 INFO (qtp1345914338-17203) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=06aa7c4c-b351-4ef2-a702-ec37a61485a1&property.customKey=customVal&maxShardsPerNode=4&name=mytestbackup&action=RESTORE&location=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001/mybackup-001&createNodeSet=127.0.0.1:36291_solr&collection=backuprestore_restored&createNodeSet.shuffle=true&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1705532 INFO (qtp1345914338-17261) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1705533 INFO (qtp1345914338-17261) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1705533 INFO (OverseerCollectionConfigSetProcessor-98028152696799237-127.0.0.1:43865_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 1705535 ERROR (OverseerThreadFactory-7963-thread-3) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: backuprestore_restored operation: restore failed:org.apache.solr.common.SolrException: Solr cloud with available number of nodes:1 is insufficient for restoring a collection with 2 shards, total replicas per shard 3 and maxShardsPerNode 4. Consider increasing maxShardsPerNode value OR number of available nodes.
[junit4] 2> at org.apache.solr.cloud.RestoreCmd.call(RestoreCmd.java:128)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:259)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1161)
[junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 1705538 INFO (OverseerThreadFactory-7963-thread-3) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 1706450 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Last replication failed, so I'll force replication
[junit4] 2> 1706450 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:36291/solr/backuprestore_shard1_replica_n1/
[junit4] 2> 1706450 INFO (qtp1688637874-17196) [ ] 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> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 1495790907632
[junit4] 2> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1706451 INFO (qtp1688637874-17198) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 1706451 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 11
[junit4] 2> 1706452 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=true) to MockDirectoryWrapper(RAMDirectory@3931c7a0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ee19b18)
[junit4] 2> 1706452 INFO (qtp1688637874-17209) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706453 INFO (qtp1688637874-17206) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706454 INFO (qtp1688637874-17208) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706454 INFO (qtp1688637874-17196) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706454 INFO (qtp1688637874-17198) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706455 INFO (qtp1688637874-17209) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706455 INFO (qtp1688637874-17206) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706456 INFO (qtp1688637874-17208) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706456 INFO (qtp1688637874-17196) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706457 INFO (qtp1688637874-17198) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706457 INFO (qtp1688637874-17209) [ ] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 1706458 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=true,bytesDownloaded=1912) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@3931c7a0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ee19b18)
[junit4] 2> 1706458 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.c.SolrCore Updating index properties... index=index.20170526092828579
[junit4] 2> 1706458 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.h.IndexFetcher removing old index directory MockDirectoryWrapper(RAMDirectory@3d82ac1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2d519622)
[junit4] 2> 1706458 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1706459 INFO (indexFetcher-7980-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@49885fc8[backuprestore_shard1_replica_p1] main]
[junit4] 2> 1706459 INFO (searcherExecutor-7968-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_p1] Registered new searcher Searcher@49885fc8[backuprestore_shard1_replica_p1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C7)))}
[junit4] 2> 1706533 INFO (qtp1345914338-17281) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1706535 INFO (qtp1345914338-17281) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1706535 INFO (qtp1345914338-17207) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :deletestatus with params requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=DELETESTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1706535 INFO (qtp1345914338-17207) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=06aa7c4c-b351-4ef2-a702-ec37a61485a1&action=DELETESTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1706535 INFO (TEST-TestLocalFSCloudBackupRestore.test-seed#[1F83D253A1D8B6E4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending test
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestLocalFSCloudBackupRestore -Dtests.method=test -Dtests.seed=1F83D253A1D8B6E4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=br-FR -Dtests.timezone=Africa/Monrovia -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 4.29s J2 | TestLocalFSCloudBackupRestore.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<COMPLETED> but was:<FAILED>
[junit4] > at __randomizedtesting.SeedInfo.seed([1F83D253A1D8B6E4:97D7ED890F24DB1C]:0)
[junit4] > at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:271)
[junit4] > at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:135)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:563)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@245fe81b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2538489b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=991195358
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=95175482
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1706560 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1706561 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1706561 INFO (jetty-closer-2822-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1706562 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1706562 INFO (jetty-closer-2822-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1706562 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1706562 INFO (jetty-closer-2822-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1706563 INFO (coreCloseExecutor-8001-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_p1] CLOSING SolrCore org.apache.solr.core.SolrCore@5e9d5964
[junit4] 2> 1706563 INFO (coreCloseExecutor-8002-thread-1) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@47edf88
[junit4] 2> 1706563 INFO (coreCloseExecutor-8001-thread-2) [ ] o.a.s.c.SolrCore [backuprestore_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@576e7241
[junit4] 2> 1706563 INFO (coreCloseExecutor-8002-thread-2) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_p1] CLOSING SolrCore org.apache.solr.core.SolrCore@78b24dd
[junit4] 2> 1706563 INFO (coreCloseExecutor-8001-thread-3) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@19518ae0
[junit4] 2> 1706563 INFO (coreCloseExecutor-8001-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard1.replica_n1, tag=1466856001
[junit4] 2> 1706563 INFO (coreCloseExecutor-8002-thread-3) [ ] o.a.s.c.SolrCore [backuprestore_shard2_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@57db5f73
[junit4] 2> 1706563 INFO (coreCloseExecutor-8002-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard2.replica_p1, tag=126559453
[junit4] 2> 1706565 INFO (coreCloseExecutor-8001-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard2.replica_n2, tag=424774368
[junit4] 2> 1706565 INFO (coreCloseExecutor-8002-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard1.replica_n2, tag=75423624
[junit4] 2> 1706567 INFO (coreCloseExecutor-8001-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard1.replica_p1, tag=1587370340
[junit4] 2> 1706567 INFO (coreCloseExecutor-8002-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard1.leader, tag=75423624
[junit4] 2> 1706567 INFO (coreCloseExecutor-8002-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.backuprestore.shard2.replica_n1, tag=1473994611
[junit4] 2> 1706569 INFO (coreCloseExecutor-8001-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard1.leader, tag=1466856001
[junit4] 2> 1706569 INFO (coreCloseExecutor-8001-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard2.leader, tag=424774368
[junit4] 2> 1706569 INFO (coreCloseExecutor-8001-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard1.leader, tag=1587370340
[junit4] 2> 1706569 INFO (coreCloseExecutor-8002-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard2.leader, tag=126559453
[junit4] 2> 1706569 INFO (coreCloseExecutor-8002-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.backuprestore.shard2.leader, tag=1473994611
[junit4] 2> 1706570 INFO (jetty-closer-2822-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98028152696799237-127.0.0.1:43865_solr-n_0000000000) closing
[junit4] 2> 1706570 INFO (OverseerStateUpdate-98028152696799237-127.0.0.1:43865_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43865_solr
[junit4] 2> 1706570 INFO (zkCallback-2833-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1708070 WARN (zkCallback-2832-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1708070 WARN (zkCallback-2833-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1708070 INFO (jetty-closer-2822-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@442cfdbb{/solr,null,UNAVAILABLE}
[junit4] 2> 1708071 INFO (jetty-closer-2822-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6a7e0d98{/solr,null,UNAVAILABLE}
[junit4] 2> 1708071 ERROR (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1708071 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[1F83D253A1D8B6E4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34097 34097
[junit4] 2> 1708105 INFO (Thread-3695) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34097 34097
[junit4] 2> 1708105 WARN (Thread-3695) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 2 /solr/collections/backuprestore/state.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> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestLocalFSCloudBackupRestore_1F83D253A1D8B6E4-001
[junit4] 2> May 26, 2017 9:28:30 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=true): {}, locale=br-FR, timezone=Africa/Monrovia
[junit4] 2> NOTE: Linux 4.8.0-52-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=8,threads=1,free=195657864,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestTolerantSearch, TestTlogReplica, TestReversedWildcardFilterFactory, TestManagedSchemaThreadSafety, TlogReplayBufferedWhileIndexingTest, DocValuesNotIndexedTest, TestExtendedDismaxParser, TestSmileRequest, OverseerTest, DistributedDebugComponentTest, SegmentsInfoRequestHandlerTest, NoCacheHeaderTest, RequestHandlersTest, TestPHPSerializedResponseWriter, SuggesterWFSTTest, TestCloudRecovery, TestRequestForwarding, SolrCoreMetricManagerTest, TestNoOpRegenerator, CurrencyFieldXmlFileTest, SolrCLIZkUtilsTest, SuggesterTSTTest, TestSegmentSorting, PrimitiveFieldTypeTest, ChaosMonkeyNothingIsSafeTest, TestGraphMLResponseWriter, NodeMutatorTest, BlobRepositoryCloudTest, TestDocSet, HighlighterMaxOffsetTest, TestCollationField, SpatialRPTFieldTypeTest, MissingSegmentRecoveryTest, GraphQueryTest, TestDistributedMissingSort, ParsingFieldUpdateProcessorsTest, TestSQLHandlerNonCloud, CollectionsAPIAsyncDistributedZkTest, HardAutoCommitTest, CustomCollectionTest, AnalysisErrorHandlingTest, UninvertDocValuesMergePolicyTest, BufferStoreTest, TestCoreDiscovery, OverseerStatusTest, FullSolrCloudDistribCmdsTest, AutoCommitTest, TestClusterStateMutator, ExternalFileFieldSortTest, TestCloudJSONFacetJoinDomain, JSONWriterTest, EchoParamsTest, TestPullReplica, DistribJoinFromCollectionTest, TestCSVResponseWriter, HdfsSyncSliceTest, LeaderInitiatedRecoveryOnCommitTest, TestIndexingPerformance, SolrTestCaseJ4Test, TestZkChroot, TestBinaryField, TestPayloadScoreQParserPlugin, AsyncCallRequestStatusResponseTest, TestGroupingSearch, TestRandomRequestDistribution, TestChildDocTransformer, TestDownShardTolerantSearch, ExplicitHLLTest, LeaderElectionContextKeyTest, DeleteStatusTest, TestOrdValues, TemplateUpdateProcessorTest, ClassificationUpdateProcessorFactoryTest, TestWriterPerf, PeerSyncWithIndexFingerprintCachingTest, ConjunctionSolrSpellCheckerTest, TestNumericTerms64, TestFastOutputStream, HdfsChaosMonkeySafeLeaderTest, TestSystemCollAutoCreate, SSLMigrationTest, CoreAdminRequestStatusTest, TestSolrCoreSnapshots, RecoveryZkTest, LeaderElectionTest, TestRawResponseWriter, TestFieldCacheWithThreads, BinaryUpdateRequestHandlerTest, AnalyticsMergeStrategyTest, TestIBSimilarityFactory, StatelessScriptUpdateProcessorFactoryTest, TestJsonFacetRefinement, TestQuerySenderNoQuery, TestFieldCacheSort, SolrCoreCheckLockOnStartupTest, TestCollectionAPIs, TestCopyFieldCollectionResource, BasicAuthIntegrationTest, RecoveryAfterSoftCommitTest, OverseerCollectionConfigSetProcessorTest, TestLuceneMatchVersion, TestPhraseSuggestions, SimpleFacetsTest, TestStressCloudBlindAtomicUpdates, TestSort, TestBlendedInfixSuggestions, TestReloadAndDeleteDocs, InfixSuggestersTest, TestObjectReleaseTracker, LargeFieldTest, ActionThrottleTest, TestHighFrequencyDictionaryFactory, TestHashQParserPlugin, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, ShardRoutingTest, TestReplicationHandler, TestRandomFaceting, ZkCLITest, ShardRoutingCustomTest, TestFaceting, TestRecovery, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestStressReorder, TestJoin, DistributedTermsComponentTest, QueryElevationComponentTest, PeerSyncTest, DirectUpdateHandlerTest, TestIndexSearcher, SoftAutoCommitTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, MBeansHandlerTest, JsonLoaderTest, TestComponentsName, SOLR749Test, AlternateDirectoryTest, SolrIndexConfigTest, TestStressRecovery, TestHighlightDedupGrouping, TestPathTrie, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, ConnectionReuseTest, CdcrReplicationDistributedZkTest, CdcrReplicationHandlerTest, CdcrRequestHandlerTest, CdcrVersionReplicationTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, CloudExitableDirectoryReaderTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, ConnectionManagerTest, DeleteInactiveReplicaTest, DeleteNodeTest, DistribDocExpirationUpdateProcessorTest, MigrateRouteKeyTest, OverseerModifyCollectionTest, PeerSyncReplicationTest, ReplaceNodeTest, TestCloudInspectUtil, TestClusterProperties, TestCollectionAPI, TestCryptoKeys, TestHdfsCloudBackupRestore, TestLeaderElectionWithEmptyReplica, TestLeaderElectionZkExpiry, TestLocalFSCloudBackupRestore]
[junit4] Completed [530/715 (1!)] on J2 in 7.06s, 1 test, 1 failure <<< FAILURES!
[...truncated 36934 lines...]