Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1109/ Java: 32bit/jdk1.8.0_144 -server -XX:+UseG1GC
1 tests failed. FAILED: org.apache.solr.cloud.TestHdfsCloudBackupRestore.test Error Message: Error from server at https://127.0.0.1:42387/solr: Timed out waiting to see all replicas: [hdfsbackuprestore_restored_shard2_replica_n85] in cluster state. Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:42387/solr: Timed out waiting to see all replicas: [hdfsbackuprestore_restored_shard2_replica_n85] in cluster state. at __randomizedtesting.SeedInfo.seed([6138D22396EA590:8E47B2F89792C868]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244) 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.sendRequest(CloudSolrClient.java:1104) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211) at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:285) at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:140) 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:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) 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:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 13469 lines...] [junit4] Suite: org.apache.solr.cloud.TestHdfsCloudBackupRestore [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/init-core-data-001 [junit4] 2> 2043463 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4 [junit4] 2> 2043463 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 2043464 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 2043465 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 1> Formatting using clusterid: testClusterID [junit4] 2> 2043527 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties [junit4] 2> 2043546 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j [junit4] 2> 2043547 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log jetty-6.1.26 [junit4] 2> 2043565 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_localdomain_34411_hdfs____.lfptxv/webapp [junit4] 2> 2044140 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost.localdomain:34411 [junit4] 2> 2044344 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j [junit4] 2> 2044345 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log jetty-6.1.26 [junit4] 2> 2044360 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_46159_datanode____.r177wm/webapp [junit4] 2> 2044932 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:46159 [junit4] 2> 2044972 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j [junit4] 2> 2044973 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log jetty-6.1.26 [junit4] 2> 2044985 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Extract jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.4-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_34901_datanode____ygklsw/webapp [junit4] 2> 2045467 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:34901 [junit4] 2> 2045798 ERROR (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-001/hdfsBaseDir/data/data1/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-001/hdfsBaseDir/data/data2/]] heartbeating to localhost.localdomain/127.0.0.1:45241) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000 [junit4] 2> 2045798 ERROR (DataNode: [[[DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-001/hdfsBaseDir/data/data3/, [DISK]file:/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-001/hdfsBaseDir/data/data4/]] heartbeating to localhost.localdomain/127.0.0.1:45241) [ ] o.a.h.h.s.d.DirectoryScanner dfs.datanode.directoryscan.throttle.limit.ms.per.sec set to value below 1 ms/sec. Assuming default value of 1000 [junit4] 2> 2045808 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x98a3db8dfaabc: from storage DS-4200e4f9-695a-4b1f-b29d-bc6dbfe18108 node DatanodeRegistration(127.0.0.1:33299, datanodeUuid=7141e948-b472-4b33-897d-47546a51efc3, infoPort=41515, infoSecurePort=0, ipcPort=39413, storageInfo=lv=-56;cid=testClusterID;nsid=1585893897;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs [junit4] 2> 2045808 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x98a3db8dfaabc: from storage DS-6b9b635f-0914-427c-b9df-f757063022c6 node DatanodeRegistration(127.0.0.1:33299, datanodeUuid=7141e948-b472-4b33-897d-47546a51efc3, infoPort=41515, infoSecurePort=0, ipcPort=39413, storageInfo=lv=-56;cid=testClusterID;nsid=1585893897;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs [junit4] 2> 2045814 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x98a3db8dfaac0: from storage DS-5a40da13-e3d4-4016-8ff2-6ae25cd6e227 node DatanodeRegistration(127.0.0.1:33213, datanodeUuid=73773d30-d3a1-4751-a1e4-b2da7ff9c87c, infoPort=45915, infoSecurePort=0, ipcPort=35093, storageInfo=lv=-56;cid=testClusterID;nsid=1585893897;c=0), blocks: 0, hasStaleStorage: true, processing time: 4 msecs [junit4] 2> 2045814 INFO (Block report processor) [ ] BlockStateChange BLOCK* processReport 0x98a3db8dfaac0: from storage DS-5b7e3ffa-158b-4a3f-b404-426abae2e0c6 node DatanodeRegistration(127.0.0.1:33213, datanodeUuid=73773d30-d3a1-4751-a1e4-b2da7ff9c87c, infoPort=45915, infoSecurePort=0, ipcPort=35093, storageInfo=lv=-56;cid=testClusterID;nsid=1585893897;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs [junit4] 2> 2045899 WARN (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.TestHdfsCloudBackupRestore The NameNode is in SafeMode - Solr will wait 5 seconds and try again. [junit4] 2> 2050913 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002 [junit4] 2> 2050914 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2050914 INFO (Thread-3840) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2050914 INFO (Thread-3840) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2050915 ERROR (Thread-3840) [ ] 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> 2051014 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:38513 [junit4] 2> 2051016 INFO (zkConnectionManagerCallback-3524-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051020 INFO (jetty-launcher-3521-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2051020 INFO (jetty-launcher-3521-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2051020 INFO (jetty-launcher-3521-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1d2795e{/solr,null,AVAILABLE} [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@94ec64{/solr,null,AVAILABLE} [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@14b0f88{SSL,[ssl, http/1.1]}{127.0.0.1:42387} [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.e.j.s.Server Started @2053057ms [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42387} [junit4] 2> 2051021 ERROR (jetty-launcher-3521-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@8c21d9{SSL,[ssl, http/1.1]}{127.0.0.1:41963} [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-2) [ ] o.e.j.s.Server Started @2053057ms [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41963} [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2051021 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-03T12:55:35.731Z [junit4] 2> 2051021 ERROR (jetty-launcher-3521-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2051022 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2051022 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2051022 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2051022 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-03T12:55:35.732Z [junit4] 2> 2051023 INFO (zkConnectionManagerCallback-3526-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051023 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2051025 INFO (zkConnectionManagerCallback-3528-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051026 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2051026 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 2051028 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 2051029 INFO (jetty-launcher-3521-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38513/solr [junit4] 2> 2051030 INFO (zkConnectionManagerCallback-3532-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051030 INFO (jetty-launcher-3521-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38513/solr [junit4] 2> 2051031 INFO (zkConnectionManagerCallback-3536-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051031 INFO (zkConnectionManagerCallback-3538-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051032 INFO (zkConnectionManagerCallback-3540-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051058 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2051058 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2051058 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42387_solr [junit4] 2> 2051058 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41963_solr [junit4] 2> 2051058 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.Overseer Overseer (id=99286000312254468-127.0.0.1:42387_solr-n_0000000000) starting [junit4] 2> 2051059 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2051059 INFO (zkCallback-3535-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2051062 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42387_solr [junit4] 2> 2051062 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2051069 INFO (zkCallback-3535-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2051137 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.c.b.r.BackupRepositoryFactory Added backup repository with configuration params {type = repository,name = hdfs,class = org.apache.solr.core.backup.repository.HdfsBackupRepository,attributes = {name=hdfs, class=org.apache.solr.core.backup.repository.HdfsBackupRepository},args = {location=/backup,solr.hdfs.home=hdfs://localhost.localdomain:45241/solr,solr.hdfs.confdir=}} [junit4] 2> 2051137 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.c.b.r.BackupRepositoryFactory Default configuration for backup repository is with configuration params {type = repository,name = hdfs,class = org.apache.solr.core.backup.repository.HdfsBackupRepository,attributes = {name=hdfs, class=org.apache.solr.core.backup.repository.HdfsBackupRepository},args = {location=/backup,solr.hdfs.home=hdfs://localhost.localdomain:45241/solr,solr.hdfs.confdir=}} [junit4] 2> 2051142 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.b.r.BackupRepositoryFactory Added backup repository with configuration params {type = repository,name = hdfs,class = org.apache.solr.core.backup.repository.HdfsBackupRepository,attributes = {name=hdfs, class=org.apache.solr.core.backup.repository.HdfsBackupRepository},args = {location=/backup,solr.hdfs.home=hdfs://localhost.localdomain:45241/solr,solr.hdfs.confdir=}} [junit4] 2> 2051142 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.b.r.BackupRepositoryFactory Default configuration for backup repository is with configuration params {type = repository,name = hdfs,class = org.apache.solr.core.backup.repository.HdfsBackupRepository,attributes = {name=hdfs, class=org.apache.solr.core.backup.repository.HdfsBackupRepository},args = {location=/backup,solr.hdfs.home=hdfs://localhost.localdomain:45241/solr,solr.hdfs.confdir=}} [junit4] 2> 2051158 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051159 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051196 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051196 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051197 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051197 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2051197 INFO (jetty-launcher-3521-thread-2) [n:127.0.0.1:41963_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/. [junit4] 2> 2051198 INFO (jetty-launcher-3521-thread-1) [n:127.0.0.1:42387_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/. [junit4] 2> 2051253 INFO (zkConnectionManagerCallback-3546-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051254 INFO (zkConnectionManagerCallback-3550-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2051255 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2051255 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38513/solr ready [junit4] 2> 2051293 INFO (TEST-TestHdfsCloudBackupRestore.test-seed#[6138D22396EA590]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test [junit4] 2> 2051317 INFO (qtp14533764-16052) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf1&version=2&pullReplicas=1&property.customKey=customValue&maxShardsPerNode=3&autoAddReplicas=true&name=hdfsbackuprestore&nrtReplicas=2&action=CREATE&numShards=2&tlogReplicas=0&wt=javabin and sendToOCPQueue=true [junit4] 2> 2051322 INFO (OverseerThreadFactory-6221-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.CreateCollectionCmd Create collection hdfsbackuprestore [junit4] 2> 2051322 WARN (OverseerThreadFactory-6221-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 3 on collection hdfsbackuprestore 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> 2051426 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"hdfsbackuprestore_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:42387/solr";, [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051426 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"hdfsbackuprestore_shard1_replica_n2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:41963/solr";, [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051427 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"hdfsbackuprestore_shard1_replica_p4", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:42387/solr";, [junit4] 2> "type":"PULL", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051428 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"hdfsbackuprestore_shard2_replica_n6", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:41963/solr";, [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051428 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"hdfsbackuprestore_shard2_replica_n8", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:42387/solr";, [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051429 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"hdfsbackuprestore", [junit4] 2> "shard":"shard2", [junit4] 2> "core":"hdfsbackuprestore_shard2_replica_p10", [junit4] 2> "state":"down", [junit4] 2> "base_url":"https://127.0.0.1:41963/solr";, [junit4] 2> "type":"PULL", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 2051637 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node7&name=hdfsbackuprestore_shard1_replica_p4&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 2051637 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2051641 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node11&name=hdfsbackuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 2051641 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=hdfsbackuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 2051665 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node5&name=hdfsbackuprestore_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin [junit4] 2> 2051665 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2051674 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node12&name=hdfsbackuprestore_shard2_replica_p10&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 2051680 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node9&name=hdfsbackuprestore_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin [junit4] 2> 2051782 INFO (zkCallback-3535-thread-1-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2051782 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2051782 INFO (zkCallback-3539-thread-2-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2052648 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052649 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052653 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.s.IndexSchema [hdfsbackuprestore_shard1_replica_n1] Schema name=minimal [junit4] 2> 2052653 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.s.IndexSchema [hdfsbackuprestore_shard2_replica_n8] Schema name=minimal [junit4] 2> 2052654 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052655 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052655 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052655 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard2_replica_n8' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052655 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard1_replica_n1' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052655 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard1.replica_n1' (registry 'solr.core.hdfsbackuprestore.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052655 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard2.replica_n8' (registry 'solr.core.hdfsbackuprestore.shard2.replica_n8') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052655 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052655 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052655 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SolrCore [[hdfsbackuprestore_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/hdfsbackuprestore_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/./hdfsbackuprestore_shard1_replica_n1/data/] [junit4] 2> 2052655 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SolrCore [[hdfsbackuprestore_shard2_replica_n8] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/hdfsbackuprestore_shard2_replica_n8], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/./hdfsbackuprestore_shard2_replica_n8/data/] [junit4] 2> 2052659 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.s.IndexSchema [hdfsbackuprestore_shard1_replica_p4] Schema name=minimal [junit4] 2> 2052661 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052661 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard1_replica_p4' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052661 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard1.replica_p4' (registry 'solr.core.hdfsbackuprestore.shard1.replica_p4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052661 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052662 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.SolrCore [[hdfsbackuprestore_shard1_replica_p4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/hdfsbackuprestore_shard1_replica_p4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node1/./hdfsbackuprestore_shard1_replica_p4/data/] [junit4] 2> 2052685 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052688 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052695 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0 [junit4] 2> 2052696 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.s.IndexSchema [hdfsbackuprestore_shard1_replica_n2] Schema name=minimal [junit4] 2> 2052699 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052699 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard1_replica_n2' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052699 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard1.replica_n2' (registry 'solr.core.hdfsbackuprestore.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052699 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052700 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.SolrCore [[hdfsbackuprestore_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/hdfsbackuprestore_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/./hdfsbackuprestore_shard1_replica_n2/data/] [junit4] 2> 2052703 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.s.IndexSchema [hdfsbackuprestore_shard2_replica_n6] Schema name=minimal [junit4] 2> 2052719 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052719 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard2_replica_n6' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052719 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.s.IndexSchema [hdfsbackuprestore_shard2_replica_p10] Schema name=minimal [junit4] 2> 2052720 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard2.replica_n6' (registry 'solr.core.hdfsbackuprestore.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052720 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052720 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.SolrCore [[hdfsbackuprestore_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/hdfsbackuprestore_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/./hdfsbackuprestore_shard2_replica_n6/data/] [junit4] 2> 2052721 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 2052721 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.CoreContainer Creating SolrCore 'hdfsbackuprestore_shard2_replica_p10' using configuration from collection hdfsbackuprestore, trusted=true [junit4] 2> 2052722 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.hdfsbackuprestore.shard2.replica_p10' (registry 'solr.core.hdfsbackuprestore.shard2.replica_p10') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ecd9f3 [junit4] 2> 2052722 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2052722 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.SolrCore [[hdfsbackuprestore_shard2_replica_p10] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/hdfsbackuprestore_shard2_replica_p10], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001/tempDir-002/node2/./hdfsbackuprestore_shard2_replica_p10/data/] [junit4] 2> 2052728 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2052728 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2052729 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052729 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052732 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2052732 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c116f2[hdfsbackuprestore_shard1_replica_n1] main] [junit4] 2> 2052732 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2052733 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052733 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052734 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052734 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052735 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052735 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588576006905528320 [junit4] 2> 2052735 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.s.SolrIndexSearcher Opening [Searcher@ebad4a[hdfsbackuprestore_shard2_replica_n8] main] [junit4] 2> 2052736 INFO (searcherExecutor-6227-thread-1-processing-n:127.0.0.1:42387_solr x:hdfsbackuprestore_shard1_replica_n1 s:shard1 c:hdfsbackuprestore r:core_node3) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SolrCore [hdfsbackuprestore_shard1_replica_n1] Registered new searcher Searcher@c116f2[hdfsbackuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052737 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052737 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052739 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.s.SolrIndexSearcher Opening [Searcher@572fef[hdfsbackuprestore_shard1_replica_p4] main] [junit4] 2> 2052740 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052740 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052740 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052740 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052741 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052741 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052741 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.ZkController hdfsbackuprestore_shard1_replica_p4 starting background replication from leader [junit4] 2> 2052741 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 2052742 INFO (searcherExecutor-6226-thread-1-processing-n:127.0.0.1:42387_solr x:hdfsbackuprestore_shard2_replica_n8 s:shard2 c:hdfsbackuprestore r:core_node11) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SolrCore [hdfsbackuprestore_shard2_replica_n8] Registered new searcher Searcher@ebad4a[hdfsbackuprestore_shard2_replica_n8] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052742 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_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> 2052742 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588576006912868352 [junit4] 2> 2052742 INFO (searcherExecutor-6228-thread-1-processing-n:127.0.0.1:42387_solr x:hdfsbackuprestore_shard1_replica_p4 s:shard1 c:hdfsbackuprestore r:core_node7) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.c.SolrCore [hdfsbackuprestore_shard1_replica_p4] Registered new searcher Searcher@572fef[hdfsbackuprestore_shard1_replica_p4] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052743 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 2052743 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052745 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms [junit4] 2> 2052779 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2052779 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2052780 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052780 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052782 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@9685cb[hdfsbackuprestore_shard1_replica_n2] main] [junit4] 2> 2052783 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052783 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052783 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052783 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052783 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052784 INFO (searcherExecutor-6230-thread-1-processing-n:127.0.0.1:41963_solr x:hdfsbackuprestore_shard1_replica_n2 s:shard1 c:hdfsbackuprestore r:core_node5) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.SolrCore [hdfsbackuprestore_shard1_replica_n2] Registered new searcher Searcher@9685cb[hdfsbackuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052784 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588576006956908544 [junit4] 2> 2052785 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.s.SolrIndexSearcher Opening [Searcher@171bb4d[hdfsbackuprestore_shard2_replica_p10] main] [junit4] 2> 2052785 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052786 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052786 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052787 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.ZkController hdfsbackuprestore_shard2_replica_p10 starting background replication from leader [junit4] 2> 2052787 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03 [junit4] 2> 2052787 INFO (searcherExecutor-6233-thread-1-processing-n:127.0.0.1:41963_solr x:hdfsbackuprestore_shard2_replica_p10 s:shard2 c:hdfsbackuprestore r:core_node12) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.c.SolrCore [hdfsbackuprestore_shard2_replica_p10] Registered new searcher Searcher@171bb4d[hdfsbackuprestore_shard2_replica_p10] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052787 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 2052787 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052791 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2052792 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2052793 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2052793 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2052795 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@f783c4[hdfsbackuprestore_shard2_replica_n6] main] [junit4] 2> 2052796 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 2052796 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 2052797 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2052797 INFO (searcherExecutor-6232-thread-1-processing-n:127.0.0.1:41963_solr x:hdfsbackuprestore_shard2_replica_n6 s:shard2 c:hdfsbackuprestore r:core_node9) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.SolrCore [hdfsbackuprestore_shard2_replica_n6] Registered new searcher Searcher@f783c4[hdfsbackuprestore_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2052797 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588576006970540032 [junit4] 2> 2052846 INFO (zkCallback-3539-thread-2-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2052846 INFO (zkCallback-3535-thread-2-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2052846 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053242 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2053242 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2053242 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:42387/solr/hdfsbackuprestore_shard1_replica_n1/ [junit4] 2> 2053243 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=hdfsbackuprestore_shard1_replica_n1 url=https://127.0.0.1:42387/solr START replicas=[https://127.0.0.1:41963/solr/hdfsbackuprestore_shard1_replica_n2/] nUpdates=100 [junit4] 2> 2053246 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2053246 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2053246 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/ [junit4] 2> 2053246 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=hdfsbackuprestore_shard2_replica_n8 url=https://127.0.0.1:42387/solr START replicas=[https://127.0.0.1:41963/solr/hdfsbackuprestore_shard2_replica_n6/] nUpdates=100 [junit4] 2> 2053250 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.S.Request [hdfsbackuprestore_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> 2053252 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.S.Request [hdfsbackuprestore_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2053543 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=hdfsbackuprestore_shard1_replica_n1 url=https://127.0.0.1:42387/solr DONE. We have no versions. sync failed. [junit4] 2> 2053543 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 2053543 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_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> 2053543 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2053545 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:42387/solr/hdfsbackuprestore_shard1_replica_n1/ shard1 [junit4] 2> 2053549 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=hdfsbackuprestore_shard2_replica_n8 url=https://127.0.0.1:42387/solr DONE. We have no versions. sync failed. [junit4] 2> 2053549 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 2053549 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] 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> 2053549 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2053550 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/ shard2 [junit4] 2> 2053651 INFO (zkCallback-3539-thread-2-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053651 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053651 INFO (zkCallback-3535-thread-2-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053689 INFO (indexFetcher-6254-thread-1) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.h.IndexFetcher Replica core_node11 is leader but it's state is down, skipping replication [junit4] 2> 2053694 INFO (indexFetcher-6244-thread-1) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.h.IndexFetcher Replica core_node3 is leader but it's state is down, skipping replication [junit4] 2> 2053695 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2053696 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=hdfsbackuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2055 [junit4] 2> 2053701 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2053702 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node11&name=hdfsbackuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2060 [junit4] 2> 2053744 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node7&name=hdfsbackuprestore_shard1_replica_p4&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2107 [junit4] 2> 2053788 INFO (qtp32146622-16116) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node5&name=hdfsbackuprestore_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2122 [junit4] 2> 2053788 INFO (qtp32146622-16055) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node12 x:hdfsbackuprestore_shard2_replica_p10] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=PULL&property.customKey=customValue&coreNodeName=core_node12&name=hdfsbackuprestore_shard2_replica_p10&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2114 [junit4] 2> 2053801 INFO (qtp32146622-16045) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=hdfsbackuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node9&name=hdfsbackuprestore_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2121 [junit4] 2> 2053803 INFO (qtp14533764-16052) [n:127.0.0.1:42387_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> 2053902 INFO (zkCallback-3535-thread-2-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053902 INFO (zkCallback-3539-thread-1-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2053902 INFO (zkCallback-3539-thread-2-processing-n:127.0.0.1:41963_solr) [n:127.0.0.1:41963_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/hdfsbackuprestore/state.json] for collection [hdfsbackuprestore] has occurred - updating... (live nodes size: [2]) [junit4] 2> 2054804 INFO (qtp14533764-16052) [n:127.0.0.1:42387_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf1&version=2&pullReplicas=1&property.customKey=customValue&maxShardsPerNode=3&autoAddReplicas=true&name=hdfsbackuprestore&nrtReplicas=2&action=CREATE&numShards=2&tlogReplicas=0&wt=javabin} status=0 QTime=3486 [junit4] 2> 2054811 INFO (qtp32146622-16049) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/&wt=javabin&version=2}{add=[2 (1588576009076080640), 3 (1588576009080274944), 5 (1588576009080274945), 6 (1588576009080274946), 7 (1588576009080274947)]} 0 1 [junit4] 2> 2054812 INFO (qtp14533764-16054) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard2_replica_n8] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1588576009076080640), 3 (1588576009080274944), 5 (1588576009080274945), 6 (1588576009080274946), 7 (1588576009080274947)]} 0 6 [junit4] 2> 2054820 INFO (qtp32146622-16053) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard1_replica_n1/&wt=javabin&version=2}{add=[0 (1588576009078177792), 1 (1588576009080274944), 4 (1588576009080274945), 8 (1588576009080274946)]} 0 10 [junit4] 2> 2054820 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1588576009078177792), 1 (1588576009080274944), 4 (1588576009080274945), 8 (1588576009080274946)]} 0 13 [junit4] 2> 2054822 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588576009093906432,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2054822 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588576009093906432,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2054822 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1a51426 commitCommandVersion:1588576009093906432 [junit4] 2> 2054822 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1a3451d commitCommandVersion:1588576009093906432 [junit4] 2> 2054827 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588576009099149312,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2054827 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1fd9847 commitCommandVersion:1588576009099149312 [junit4] 2> 2054829 INFO (qtp14533764-16113) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588576009101246464,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2054829 INFO (qtp14533764-16113) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@65509e commitCommandVersion:1588576009101246464 [junit4] 2> 2055039 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@4d24cf[hdfsbackuprestore_shard2_replica_n6] main] [junit4] 2> 2055040 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2055041 INFO (searcherExecutor-6232-thread-1-processing-n:127.0.0.1:41963_solr x:hdfsbackuprestore_shard2_replica_n6 s:shard2 c:hdfsbackuprestore r:core_node9) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.c.SolrCore [hdfsbackuprestore_shard2_replica_n6] Registered new searcher Searcher@4d24cf[hdfsbackuprestore_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C5)))} [junit4] 2> 2055041 INFO (qtp32146622-16138) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 219 [junit4] 2> 2055043 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ab3b2f[hdfsbackuprestore_shard1_replica_n1] main] [junit4] 2> 2055043 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f2d90c[hdfsbackuprestore_shard1_replica_n2] main] [junit4] 2> 2055043 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2055043 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2055044 INFO (searcherExecutor-6230-thread-1-processing-n:127.0.0.1:41963_solr x:hdfsbackuprestore_shard1_replica_n2 s:shard1 c:hdfsbackuprestore r:core_node5) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.c.SolrCore [hdfsbackuprestore_shard1_replica_n2] Registered new searcher Searcher@1f2d90c[hdfsbackuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C4)))} [junit4] 2> 2055044 INFO (qtp32146622-16057) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard1 r:core_node5 x:hdfsbackuprestore_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 222 [junit4] 2> 2055044 INFO (searcherExecutor-6227-thread-1-processing-n:127.0.0.1:42387_solr x:hdfsbackuprestore_shard1_replica_n1 s:shard1 c:hdfsbackuprestore r:core_node3) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.SolrCore [hdfsbackuprestore_shard1_replica_n1] Registered new searcher Searcher@ab3b2f[hdfsbackuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C4)))} [junit4] 2> 2055044 INFO (qtp14533764-16048) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 216 [junit4] 2> 2055047 INFO (qtp14533764-16113) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.s.SolrIndexSearcher Opening [Searcher@eeeab3[hdfsbackuprestore_shard2_replica_n8] main] [junit4] 2> 2055048 INFO (qtp14533764-16113) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2055048 INFO (searcherExecutor-6226-thread-1-processing-n:127.0.0.1:42387_solr x:hdfsbackuprestore_shard2_replica_n8 s:shard2 c:hdfsbackuprestore r:core_node11) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.SolrCore [hdfsbackuprestore_shard2_replica_n8] Registered new searcher Searcher@eeeab3[hdfsbackuprestore_shard2_replica_n8] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C5)))} [junit4] 2> 2055048 INFO (qtp14533764-16113) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard2_replica_n8] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42387/solr/hdfsbackuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 219 [junit4] 2> 2055049 INFO (qtp14533764-16052) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.u.p.LogUpdateProcessorFactory [hdfsbackuprestore_shard2_replica_n8] webapp=/solr path=/update params={_stateVer_=hdfsbackuprestore:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 227 [junit4] 2> 2055050 INFO (qtp14533764-16056) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.c.S.Request [hdfsbackuprestore_shard2_replica_n8] webapp=/solr path=/select params={q=*:*&distrib=false&wt=javabin&version=2} hits=5 status=0 QTime=0 [junit4] 2> 2055050 INFO (qtp14533764-16042) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node3 x:hdfsbackuprestore_shard1_replica_n1] o.a.s.c.S.Request [hdfsbackuprestore_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&distrib=false&wt=javabin&version=2} hits=4 status=0 QTime=0 [junit4] 2> 2055051 INFO (TEST-TestHdfsCloudBackupRestore.test-seed#[6138D22396EA590]) [ ] o.a.s.c.AbstractCloudBackupRestoreTestCase Triggering Backup command [junit4] 2> 2055051 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :backup with params async=6b083a09-9c6d-432a-8cef-dd64fcab1cde&name=mytestbackup&action=BACKUP&collection=hdfsbackuprestore&repository=hdfs&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2055052 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost.localdomain:45241/solr [junit4] 2> 2055052 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled [junit4] 2> 2055062 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=6b083a09-9c6d-432a-8cef-dd64fcab1cde&name=mytestbackup&action=BACKUP&collection=hdfsbackuprestore&repository=hdfs&wt=javabin&version=2} status=0 QTime=11 [junit4] 2> 2055063 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=6b083a09-9c6d-432a-8cef-dd64fcab1cde&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2055063 INFO (qtp14533764-16046) [n:127.0.0.1:42387_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=6b083a09-9c6d-432a-8cef-dd64fcab1cde&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2055066 INFO (OverseerThreadFactory-6221-thread-2-processing-n:127.0.0.1:42387_solr) [n:127.0.0.1:42387_solr ] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost.localdomain:45241/solr [junit4] 2> 2055066 INFO (OverseerCollectionConfigSetProcessor-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/c [...truncated too long message...] 2> 2089922 INFO (coreCloseExecutor-6270-thread-3) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@19198a4: rootName = null, domain = solr.core.hdfsbackuprestore.shard2.replica_n6, service url = null, agent id = null] for registry solr.core.hdfsbackuprestore.shard2.replica_n6 / com.codahale.metrics.MetricRegistry@19a9565 [junit4] 2> 2089924 INFO (coreCloseExecutor-6271-thread-4) [n:127.0.0.1:42387_solr c:hdfsbackuprestore_restored s:shard1 r:core_node84 x:hdfsbackuprestore_restored_shard1_replica_n83] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.hdfsbackuprestore_restored.shard1.replica_n83, tag=21588703 [junit4] 2> 2089925 INFO (coreCloseExecutor-6271-thread-4) [n:127.0.0.1:42387_solr c:hdfsbackuprestore_restored s:shard1 r:core_node84 x:hdfsbackuprestore_restored_shard1_replica_n83] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@111f3ca: rootName = null, domain = solr.core.hdfsbackuprestore_restored.shard1.replica_n83, service url = null, agent id = null] for registry solr.core.hdfsbackuprestore_restored.shard1.replica_n83 / com.codahale.metrics.MetricRegistry@4e24fc [junit4] 2> 2089928 INFO (coreCloseExecutor-6270-thread-4) [n:127.0.0.1:41963_solr c:hdfsbackuprestore_restored s:shard2 r:core_node82 x:hdfsbackuprestore_restored_shard2_replica_n81] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.hdfsbackuprestore_restored.shard2.leader, tag=16599370 [junit4] 2> 2089929 INFO (coreCloseExecutor-6270-thread-3) [n:127.0.0.1:41963_solr c:hdfsbackuprestore s:shard2 r:core_node9 x:hdfsbackuprestore_shard2_replica_n6] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.hdfsbackuprestore.shard2.leader, tag=31018469 [junit4] 2> 2089931 INFO (jetty-closer-3522-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@94ec64{/solr,null,UNAVAILABLE} [junit4] 2> 2089932 INFO (coreCloseExecutor-6271-thread-2) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard1 r:core_node7 x:hdfsbackuprestore_shard1_replica_p4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.hdfsbackuprestore.shard1.leader, tag=13695963 [junit4] 2> 2089932 INFO (coreCloseExecutor-6271-thread-3) [n:127.0.0.1:42387_solr c:hdfsbackuprestore s:shard2 r:core_node11 x:hdfsbackuprestore_shard2_replica_n8] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.hdfsbackuprestore.shard2.leader, tag=9274380 [junit4] 2> 2089932 INFO (coreCloseExecutor-6271-thread-4) [n:127.0.0.1:42387_solr c:hdfsbackuprestore_restored s:shard1 r:core_node84 x:hdfsbackuprestore_restored_shard1_replica_n83] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.hdfsbackuprestore_restored.shard1.leader, tag=21588703 [junit4] 2> 2089934 INFO (jetty-closer-3522-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99286000312254468-127.0.0.1:42387_solr-n_0000000000) closing [junit4] 2> 2089934 INFO (OverseerStateUpdate-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:42387_solr [junit4] 2> 2089934 WARN (OverseerAutoScalingTriggerThread-99286000312254468-127.0.0.1:42387_solr-n_0000000000) [n:127.0.0.1:42387_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 2089936 INFO (jetty-closer-3522-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1d2795e{/solr,null,UNAVAILABLE} [junit4] 2> 2089936 ERROR (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-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> 2089936 INFO (SUITE-TestHdfsCloudBackupRestore-seed#[6138D22396EA590]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:38513 38513 [junit4] 2> 2089963 INFO (Thread-3840) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:38513 38513 [junit4] 2> 2089964 WARN (Thread-3840) [ ] 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> 2 /solr/security.json [junit4] 2> 2 /solr/configs/conf1 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 8 /solr/collections/hdfsbackuprestore_restored/state.json [junit4] 2> 7 /solr/collections/hdfsbackuprestore/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> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestHdfsCloudBackupRestore_6138D22396EA590-001 [junit4] 2> Jan 03, 2018 12:56:14 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 68 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {shard_s=PostingsFormat(name=Direct), id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{}, maxPointsInLeafNode=191, maxMBSortInHeap=6.440772782226201, sim=RandomSimilarity(queryNorm=false): {}, locale=es-CO, timezone=Pacific/Pago_Pago [junit4] 2> NOTE: Linux 4.10.0-40-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=2,free=181947176,total=536870912 [junit4] 2> NOTE: All tests run in this JVM: [MultiTermTest, TestSolrCloudWithHadoopAuthPlugin, TestRandomFaceting, ResponseLogComponentTest, TestOrdValues, DateFieldTest, SaslZkACLProviderTest, StatsReloadRaceTest, TestXmlQParser, TestObjectReleaseTracker, TestConfig, TestIBSimilarityFactory, CacheHeaderTest, OverseerTaskQueueTest, TestReqParamsAPI, CleanupOldIndexTest, TestFilteredDocIdSet, TestSolrCloudWithDelegationTokens, ConnectionManagerTest, ManagedSchemaRoundRobinCloudTest, TestSchemaResource, DistributedMLTComponentTest, TestStressVersions, TestRandomDVFaceting, ReplicaListTransformerTest, TestCodecSupport, UpdateParamsTest, DataDrivenBlockJoinTest, VMParamsZkACLAndCredentialsProvidersTest, MetricTriggerTest, TestManagedResource, TestConfigsApi, TestPHPSerializedResponseWriter, TestSystemCollAutoCreate, DistributedFacetPivotWhiteBoxTest, CachingDirectoryFactoryTest, DeleteReplicaTest, ClassificationUpdateProcessorTest, DistributedFacetPivotLongTailTest, TestQueryWrapperFilter, BasicDistributedZkTest, BasicAuthIntegrationTest, TestBulkSchemaAPI, BigEndianAscendingWordDeserializerTest, ForceLeaderTest, TestDistribStateManager, DistributedExpandComponentTest, HdfsChaosMonkeyNothingIsSafeTest, TestComponentsName, TestOnReconnectListenerSupport, TestFastOutputStream, TestSha256AuthenticationProvider, TestReRankQParserPlugin, TestPointFields, TestFieldCacheReopen, ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestDistributedSearch, SolrMetricReporterTest, QueryResultKeyTest, TestPhraseSuggestions, SearchHandlerTest, TermVectorComponentTest, TestIntervalFaceting, TestBadConfig, TestAddFieldRealTimeGet, TestRebalanceLeaders, TriggerIntegrationTest, MissingSegmentRecoveryTest, PropertiesRequestHandlerTest, SimpleCollectionCreateDeleteTest, TestSolrJ, TestUtilizeNode, TestNumericTokenStream, TestInPlaceUpdatesDistrib, SimpleFacetsTest, URLClassifyProcessorTest, TestCloudPseudoReturnFields, DistribCursorPagingTest, DocumentBuilderTest, MetricsConfigTest, CollectionsAPISolrJTest, ExplicitHLLTest, TestLuceneIndexBackCompat, TestOverriddenPrefixQueryForCustomFieldType, PeerSyncTest, TestStandardQParsers, MinimalSchemaTest, TestHighlightDedupGrouping, ExecutePlanActionTest, AnalyticsQueryTest, LeaderInitiatedRecoveryOnShardRestartTest, ActionThrottleTest, SearchRateTriggerTest, TestSort, SoftAutoCommitTest, TestExactSharedStatsCache, TestFreeTextSuggestions, StressHdfsTest, TestRetrieveFieldsOptimizer, TestImplicitCoreProperties, TestMultiValuedNumericRangeQuery, TestBinaryField, TestCSVLoader, TestInitQParser, TimeRoutedAliasUpdateProcessorTest, TestSweetSpotSimilarityFactory, TestPostingsSolrHighlighter, TestFoldingMultitermQuery, BasicZkTest, UpdateRequestProcessorFactoryTest, DirectoryFactoryTest, TestPolicyCloud, TestStressCloudBlindAtomicUpdates, SolrSlf4jReporterTest, TestCloudInspectUtil, TestCloudSchemaless, SliceStateTest, TestMissingGroups, TestManagedSynonymFilterFactory, CdcrVersionReplicationTest, TestSolrCloudSnapshots, TestFieldTypeCollectionResource, SolrPluginUtilsTest, BooleanFieldTest, TestComplexPhraseQParserPlugin, TestConfigSetImmutable, TestValueSourceCache, FieldAnalysisRequestHandlerTest, QueryParsingTest, JsonLoaderTest, PingRequestHandlerTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, ConnectionReuseTest, AliasIntegrationTest, AsyncCallRequestStatusResponseTest, ChaosMonkeySafeLeaderWithPullReplicasTest, DistribJoinFromCollectionTest, LeaderElectionContextKeyTest, LeaderFailoverAfterPartitionTest, MultiThreadedOCPTest, OverseerCollectionConfigSetProcessorTest, OverseerModifyCollectionTest, OverseerStatusTest, ReplaceNodeTest, SharedFSAutoReplicaFailoverTest, SolrCLIZkUtilsTest, SolrCloudExampleTest, TestClusterProperties, TestCollectionAPI, TestConfigSetsAPI, TestDownShardTolerantSearch, TestHdfsCloudBackupRestore] [junit4] Completed [554/764 (1!)] on J0 in 54.46s, 1 test, 1 error <<< FAILURES! [...truncated 44653 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
