You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/11/27 15:28:50 UTC
[JENKINS] Lucene-Solr-6.x-Solaris (64bit/jdk1.8.0) - Build # 518 -
Failure!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Solaris/518/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.cloud.RecoveryZkTest.test
Error Message:
Error from server at https://127.0.0.1:35281/solr: Cannot create collection recoverytest. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 1. This allows a maximum of 1 to be created. Value of numShards is 1 and value of replicationFactor is 2. This requires 2 shards to be created (higher than the allowed number)
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:35281/solr: Cannot create collection recoverytest. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 1. This allows a maximum of 1 to be created. Value of numShards is 1 and value of replicationFactor is 2. This requires 2 shards to be created (higher than the allowed number)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:593)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:435)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:387)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1340)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1091)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1033)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:149)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:166)
at org.apache.solr.cloud.RecoveryZkTest.test(RecoveryZkTest.java:68)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
Error Message:
ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43) at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130) at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94) at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102) at sun.reflect.GeneratedConstructorAccessor161.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:705) at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:767) at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1006) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:871) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:775) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:842) at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:498) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43)
at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102)
at sun.reflect.GeneratedConstructorAccessor161.newInstance(Unknown Source)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:705)
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:767)
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1006)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:871)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:775)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:842)
at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:498)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([8B11045FDE87FCC5]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:260)
at sun.reflect.GeneratedMethodAccessor27.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11226 lines...]
[junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.RecoveryZkTest_8B11045FDE87FCC5-001/init-core-data-001
[junit4] 2> 722886 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 722887 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.RecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001
[junit4] 2> 722888 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 722888 INFO (Thread-1242) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 722888 INFO (Thread-1242) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 722988 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34726
[junit4] 2> 723006 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 723008 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7e50e879{/solr,null,AVAILABLE}
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7d32a5dd{SSL,[ssl, http/1.1]}{127.0.0.1:59078}
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.Server Started @725880ms
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59078}
[junit4] 2> 723011 ERROR (jetty-launcher-687-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 723011 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-27T14:27:44.190Z
[junit4] 2> 723015 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 723016 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@52241a60{/solr,null,AVAILABLE}
[junit4] 2> 723018 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7bec9988{SSL,[ssl, http/1.1]}{127.0.0.1:35281}
[junit4] 2> 723018 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.Server Started @725888ms
[junit4] 2> 723018 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35281}
[junit4] 2> 723018 ERROR (jetty-launcher-687-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 723019 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 723019 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 723019 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 723019 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-27T14:27:44.198Z
[junit4] 2> 723028 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 723240 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 723252 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 723253 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34726/solr
[junit4] 2> 723286 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 723286 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34726/solr
[junit4] 2> 723314 INFO (jetty-launcher-687-thread-1) [n:127.0.0.1:59078_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:59078_solr
[junit4] 2> 723317 INFO (jetty-launcher-687-thread-1) [n:127.0.0.1:59078_solr ] o.a.s.c.Overseer Overseer (id=97010113843757060-127.0.0.1:59078_solr-n_0000000000) starting
[junit4] 2> 723325 INFO (jetty-launcher-687-thread-1) [n:127.0.0.1:59078_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59078_solr
[junit4] 2> 723395 INFO (jetty-launcher-687-thread-1) [n:127.0.0.1:59078_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.RecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node1/.
[junit4] 2> 723423 INFO (jetty-launcher-687-thread-2) [n:127.0.0.1:35281_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 723429 INFO (jetty-launcher-687-thread-2) [n:127.0.0.1:35281_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35281_solr
[junit4] 2> 723510 INFO (jetty-launcher-687-thread-2) [n:127.0.0.1:35281_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.RecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node2/.
[junit4] 2> 723518 INFO (zkCallback-694-thread-1-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 723528 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 723529 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34726/solr ready
[junit4] 2> 723535 INFO (zkCallback-699-thread-1-processing-n:127.0.0.1:35281_solr) [n:127.0.0.1:35281_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 723550 INFO (TEST-RecoveryZkTest.test-seed#[8B11045FDE87FCC5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 723603 INFO (qtp1955414459-4683) [n:127.0.0.1:35281_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 723610 INFO (OverseerThreadFactory-2129-thread-1-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.CreateCollectionCmd Create collection recoverytest
[junit4] 2> 723610 WARN (OverseerThreadFactory-2129-thread-1-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 2 on collection recoverytest is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 723611 ERROR (OverseerThreadFactory-2129-thread-1-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: recoverytest operation: create failed:org.apache.solr.common.SolrException: Cannot create collection recoverytest. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 1. This allows a maximum of 1 to be created. Value of numShards is 1 and value of replicationFactor is 2. This requires 2 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:148)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 723645 INFO (qtp1955414459-4683) [n:127.0.0.1:35281_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2} status=400 QTime=41
[junit4] 2> 723648 INFO (TEST-RecoveryZkTest.test-seed#[8B11045FDE87FCC5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending test
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.method=test -Dtests.seed=8B11045FDE87FCC5 -Dtests.slow=true -Dtests.locale=ar -Dtests.timezone=Atlantic/Madeira -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.12s J0 | RecoveryZkTest.test <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:35281/solr: Cannot create collection recoverytest. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 1. This allows a maximum of 1 to be created. Value of numShards is 1 and value of replicationFactor is 2. This requires 2 shards to be created (higher than the allowed number)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:593)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:435)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:387)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1340)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1091)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1033)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:149)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:166)
[junit4] > at org.apache.solr.cloud.RecoveryZkTest.test(RecoveryZkTest.java:68)
[junit4] > at java.lang.Thread.run(Thread.java:745)Throwable #2: java.lang.NullPointerException
[junit4] > at org.apache.solr.cloud.RecoveryZkTest.stopThreads(RecoveryZkTest.java:55)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 723658 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7d32a5dd{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 723658 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=101617813
[junit4] 2> 723662 INFO (jetty-launcher-687-thread-2) [ ] o.a.s.c.Overseer Overseer (id=97010113843757060-127.0.0.1:59078_solr-n_0000000000) closing
[junit4] 2> 723663 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7bec9988{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 723664 INFO (jetty-launcher-687-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=674466636
[junit4] 2> 723672 INFO (jetty-launcher-687-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@52241a60{/solr,null,UNAVAILABLE}
[junit4] 2> 725183 WARN (zkCallback-694-thread-2-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 725184 WARN (OverseerStateUpdate-97010113843757060-127.0.0.1:59078_solr-n_0000000000) [n:127.0.0.1:59078_solr ] o.a.s.c.Overseer Solr cannot talk to ZK, exiting Overseer work queue loop
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /live_nodes
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:339)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:336)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:336)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:664)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:268)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:140)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 725184 INFO (OverseerStateUpdate-97010113843757060-127.0.0.1:59078_solr-n_0000000000) [n:127.0.0.1:59078_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:59078_solr
[junit4] 2> 725184 INFO (zkCallback-694-thread-1-processing-n:127.0.0.1:59078_solr) [n:127.0.0.1:59078_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 725185 INFO (jetty-launcher-687-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7e50e879{/solr,null,UNAVAILABLE}
[junit4] 2> 725194 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34726 34726
[junit4] 2> 725219 INFO (Thread-1242) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34726 34726
[junit4] 2> 725220 WARN (Thread-1242) [ ] 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>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[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> 725221 INFO (SUITE-RecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.RecoveryZkTest_8B11045FDE87FCC5-001
[junit4] 2> Nov 27, 2016 2:27:46 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {}, docValues:{}, maxPointsInLeafNode=455, maxMBSortInHeap=7.682942685719383, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=ar, timezone=Atlantic/Madeira
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=86406184,total=261984256
[junit4] 2> NOTE: All tests run in this JVM: [TestPKIAuthenticationPlugin, TestDocumentBuilder, ResponseHeaderTest, TestShardHandlerFactory, TestOrdValues, TestSolrConfigHandlerConcurrent, IndexBasedSpellCheckerTest, TestRandomRequestDistribution, TestManagedSchemaAPI, TestSolrCloudSnapshots, TestConfigReload, TestFieldCacheVsDocValues, HdfsUnloadDistributedZkTest, TestPhraseSuggestions, VersionInfoTest, ShardRoutingTest, TestHashPartitioner, TestCustomDocTransformer, HighlighterTest, CollectionsAPIAsyncDistributedZkTest, TestUpdate, TestComplexPhraseQParserPlugin, TestTrackingShardHandlerFactory, HardAutoCommitTest, RestartWhileUpdatingTest, TestUseDocValuesAsStored2, TestStressReorder, TestComponentsName, TestConfigOverlay, HdfsCollectionsAPIDistributedZkTest, CdcrUpdateLogTest, TestSchemaNameResource, SolrCoreTest, SampleTest, TestLeaderElectionWithEmptyReplica, HttpPartitionTest, TestCryptoKeys, TestDistributedSearch, DistribDocExpirationUpdateProcessorTest, PrimitiveFieldTypeTest, TestSolrIndexConfig, CurrencyFieldXmlFileTest, SpatialHeatmapFacetsTest, TestLeaderInitiatedRecoveryThread, ReplicaListTransformerTest, TestStressRecovery, TestOverriddenPrefixQueryForCustomFieldType, ResponseLogComponentTest, BJQParserTest, TestXmlQParserPlugin, RecoveryZkTest]
[junit4] Completed [170/658 (1!)] on J0 in 3.25s, 1 test, 1 error <<< FAILURES!
[...truncated 1096 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/init-core-data-001
[junit4] 2> 2423136 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2423137 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001
[junit4] 2> 2423137 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2423137 INFO (Thread-6255) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2423137 INFO (Thread-6255) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2423237 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33037
[junit4] 2> 2423250 INFO (jetty-launcher-10861-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2423252 INFO (jetty-launcher-10861-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a606bd4{/solr,null,AVAILABLE}
[junit4] 2> 2423250 INFO (jetty-launcher-10861-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@17aa2228{/solr,null,AVAILABLE}
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@11094a56{SSL,[ssl, http/1.1]}{127.0.0.1:46673}
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-1) [ ] o.e.j.s.Server Started @2426868ms
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46673}
[junit4] 2> 2423257 ERROR (jetty-launcher-10861-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2423257 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2423258 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2423258 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-27T14:56:04.437Z
[junit4] 2> 2423258 INFO (jetty-launcher-10861-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@46ea1f5c{SSL,[ssl, http/1.1]}{127.0.0.1:48362}
[junit4] 2> 2423258 INFO (jetty-launcher-10861-thread-2) [ ] o.e.j.s.Server Started @2426870ms
[junit4] 2> 2423258 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48362}
[junit4] 2> 2423258 ERROR (jetty-launcher-10861-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2423259 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.4.0
[junit4] 2> 2423259 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2423259 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2423259 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-27T14:56:04.438Z
[junit4] 2> 2423262 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2423262 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2423270 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2423270 INFO (jetty-launcher-10861-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33037/solr
[junit4] 2> 2423271 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2423272 INFO (jetty-launcher-10861-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33037/solr
[junit4] 2> 2423307 INFO (jetty-launcher-10861-thread-1) [n:127.0.0.1:46673_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46673_solr
[junit4] 2> 2423308 INFO (jetty-launcher-10861-thread-2) [n:127.0.0.1:48362_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48362_solr
[junit4] 2> 2423310 INFO (jetty-launcher-10861-thread-1) [n:127.0.0.1:46673_solr ] o.a.s.c.Overseer Overseer (id=97010225271144454-127.0.0.1:46673_solr-n_0000000000) starting
[junit4] 2> 2423323 INFO (jetty-launcher-10861-thread-1) [n:127.0.0.1:46673_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46673_solr
[junit4] 2> 2423380 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2423394 INFO (zkCallback-10872-thread-1-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2423445 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2423489 INFO (OverseerStateUpdate-97010225271144454-127.0.0.1:46673_solr-n_0000000000) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2423515 INFO (jetty-launcher-10861-thread-1) [n:127.0.0.1:46673_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node1/.
[junit4] 2> 2423593 INFO (jetty-launcher-10861-thread-2) [n:127.0.0.1:48362_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node2/.
[junit4] 2> 2423601 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2423603 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33037/solr ready
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 2423640 WARN (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 2423649 WARN (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2423651 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2423665 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs to ./temp/Jetty_solaris.vm_46060_hdfs____zb6w1m/webapp
[junit4] 2> 2424216 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@solaris-vm:46060
[junit4] 2> 2424345 WARN (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2424346 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2424360 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_41896_datanode____src61r/webapp
[junit4] 2> 2424820 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:41896
[junit4] 2> 2424895 WARN (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2424896 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2424912 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_64880_datanode____emwjo9/webapp
[junit4] 2> 2424957 INFO (IPC Server handler 2 on 52615) [ ] BlockStateChange BLOCK* processReport: from storage DS-38811a91-dbc5-4f0e-9d5f-96d3c1408fcb node DatanodeRegistration(127.0.0.1:58758, datanodeUuid=0e41dbbf-963c-4d5a-89e1-a407734c9ee9, infoPort=62601, infoSecurePort=0, ipcPort=36459, storageInfo=lv=-56;cid=testClusterID;nsid=1862498236;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2424957 INFO (IPC Server handler 2 on 52615) [ ] BlockStateChange BLOCK* processReport: from storage DS-31a6424c-08ad-4f03-8663-73d81dac5516 node DatanodeRegistration(127.0.0.1:58758, datanodeUuid=0e41dbbf-963c-4d5a-89e1-a407734c9ee9, infoPort=62601, infoSecurePort=0, ipcPort=36459, storageInfo=lv=-56;cid=testClusterID;nsid=1862498236;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2425453 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:64880
[junit4] 2> 2426030 INFO (IPC Server handler 5 on 52615) [ ] BlockStateChange BLOCK* processReport: from storage DS-165617a1-5bfd-453b-9219-8edf920eacd9 node DatanodeRegistration(127.0.0.1:38289, datanodeUuid=c71bb449-fb2e-4319-96f7-fa7381210cd9, infoPort=43425, infoSecurePort=0, ipcPort=59954, storageInfo=lv=-56;cid=testClusterID;nsid=1862498236;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2426030 INFO (IPC Server handler 5 on 52615) [ ] BlockStateChange BLOCK* processReport: from storage DS-20d5653e-c31a-4421-acca-7ef2c5693694 node DatanodeRegistration(127.0.0.1:38289, datanodeUuid=c71bb449-fb2e-4319-96f7-fa7381210cd9, infoPort=43425, infoSecurePort=0, ipcPort=59954, storageInfo=lv=-56;cid=testClusterID;nsid=1862498236;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2426170 INFO (TEST-HdfsRecoveryZkTest.test-seed#[8B11045FDE87FCC5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 2426215 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2426219 INFO (OverseerThreadFactory-9711-thread-1-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.CreateCollectionCmd Create collection recoverytest
[junit4] 2> 2426344 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2
[junit4] 2> 2426359 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2
[junit4] 2> 2426466 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2426466 INFO (zkCallback-10872-thread-1-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2427357 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2427366 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema [recoverytest_shard1_replica1] Schema name=minimal
[junit4] 2> 2427369 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2427370 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica1' using configuration from collection recoverytest
[junit4] 2> 2427370 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2427377 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:52615/data
[junit4] 2> 2427377 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2427377 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.SolrCore [[recoverytest_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node1/recoverytest_shard1_replica1], dataDir=[hdfs://solaris-vm:52615/data/recoverytest/core_node1/data/]
[junit4] 2> 2427377 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node1/data/snapshot_metadata
[junit4] 2> 2427379 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema [recoverytest_shard1_replica2] Schema name=minimal
[junit4] 2> 2427381 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2427382 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica2' using configuration from collection recoverytest
[junit4] 2> 2427383 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:52615/data
[junit4] 2> 2427383 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2427383 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.SolrCore [[recoverytest_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_8B11045FDE87FCC5-001/tempDir-001/node2/recoverytest_shard1_replica2], dataDir=[hdfs://solaris-vm:52615/data/recoverytest/core_node2/data/]
[junit4] 2> 2427383 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node2/data/snapshot_metadata
[junit4] 2> 2427386 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
[junit4] 2> 2427387 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of [16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 2427387 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Creating new global HDFS BlockCache
[junit4] 2> 2427390 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
[junit4] 2> 2427390 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of [16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 2427398 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2427399 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2427400 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node1/data
[junit4] 2> 2427400 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node2/data
[junit4] 2> 2427421 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node1/data/index
[junit4] 2> 2427429 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
[junit4] 2> 2427429 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of [16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 2427434 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2427437 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:52615/data/recoverytest/core_node2/data/index
[junit4] 2> 2427446 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
[junit4] 2> 2427446 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of [16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 2427453 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2427462 INFO (IPC Server handler 8 on 52615) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58758 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-165617a1-5bfd-453b-9219-8edf920eacd9:NORMAL:127.0.0.1:38289|RBW], ReplicaUC[[DISK]DS-38811a91-dbc5-4f0e-9d5f-96d3c1408fcb:NORMAL:127.0.0.1:58758|RBW]]} size 0
[junit4] 2> 2427465 INFO (IPC Server handler 6 on 52615) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38289 is added to blk_1073741825_1001 size 71
[junit4] 2> 2427484 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2427484 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2427484 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2427489 INFO (IPC Server handler 8 on 52615) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:58758 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-165617a1-5bfd-453b-9219-8edf920eacd9:NORMAL:127.0.0.1:38289|RBW], ReplicaUC[[DISK]DS-31a6424c-08ad-4f03-8663-73d81dac5516:NORMAL:127.0.0.1:58758|RBW]]} size 0
[junit4] 2> 2427491 INFO (IPC Server handler 4 on 52615) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:38289 is added to blk_1073741826_1002 size 71
[junit4] 2> 2428071 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2428071 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2428077 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2428077 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2428077 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2428090 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7a0b78f[recoverytest_shard1_replica1] main]
[junit4] 2> 2428091 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2428091 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2428092 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2428093 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2428093 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2428093 INFO (searcherExecutor-9716-thread-1-processing-n:127.0.0.1:46673_solr x:recoverytest_shard1_replica1 s:shard1 c:recoverytest r:core_node1) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.SolrCore [recoverytest_shard1_replica1] Registered new searcher Searcher@7a0b78f[recoverytest_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2428094 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1552163609534005248
[junit4] 2> 2428105 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2428107 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@10c338bd[recoverytest_shard1_replica2] main]
[junit4] 2> 2428109 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2428109 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2428109 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2428109 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1552163609549733888
[junit4] 2> 2428113 INFO (searcherExecutor-9717-thread-1-processing-n:127.0.0.1:48362_solr x:recoverytest_shard1_replica2 s:shard1 c:recoverytest r:core_node2) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.SolrCore [recoverytest_shard1_replica2] Registered new searcher Searcher@10c338bd[recoverytest_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2428116 INFO (zkCallback-10872-thread-3-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2428116 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2428611 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2428611 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2428611 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/
[junit4] 2> 2428612 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica1 url=https://127.0.0.1:46673/solr START replicas=[https://127.0.0.1:48362/solr/recoverytest_shard1_replica2/] nUpdates=100
[junit4] 2> 2428612 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica1 url=https://127.0.0.1:46673/solr DONE. We have no versions. sync failed.
[junit4] 2> 2428626 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.c.S.Request [recoverytest_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2428628 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2428628 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2428634 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/ shard1
[junit4] 2> 2428739 INFO (zkCallback-10872-thread-3-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2428739 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2428786 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2428805 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2} status=0 QTime=2462
[junit4] 2> 2428909 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2428910 INFO (zkCallback-10872-thread-3-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2429119 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2} status=0 QTime=2760
[junit4] 2> 2429122 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_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> 2429227 INFO (zkCallback-10872-thread-2-processing-n:127.0.0.1:46673_solr) [n:127.0.0.1:46673_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2429227 INFO (zkCallback-10871-thread-1-processing-n:127.0.0.1:48362_solr) [n:127.0.0.1:48362_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/recoverytest/state.json] for collection [recoverytest] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2430123 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3909
[junit4] 2> 2430126 INFO (TEST-HdfsRecoveryZkTest.test-seed#[8B11045FDE87FCC5]) [ ] o.a.s.c.RecoveryZkTest Indexing 700 documents
[junit4] 2> 2430174 INFO (qtp634849440-48848) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-0 (1552163611680440320)]} 0 18
[junit4] 2> 2430175 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0 (1552163611680440320)]} 0 34
[junit4] 2> 2430176 INFO (qtp634849440-48847) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-0 (1552163611673100288)]} 0 11
[junit4] 2> 2430177 INFO (qtp2127796789-48840) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0 (1552163611673100288)]} 0 44
[junit4] 2> 2430182 INFO (qtp634849440-48846) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-1 (1552163611719237632)]} 0 2
[junit4] 2> 2430182 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-1 (1552163611719237633)]} 0 2
[junit4] 2> 2430182 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1 (1552163611719237632)]} 0 4
[junit4] 2> 2430183 INFO (qtp2127796789-48836) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1 (1552163611719237633)]} 0 4
[junit4] 2> 2430190 INFO (qtp634849440-48853) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-2 (1552163611727626240)]} 0 1
[junit4] 2> 2430190 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-2 (1552163611728674816)]} 0 1
[junit4] 2> 2430190 INFO (qtp2127796789-48841) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2 (1552163611728674816)]} 0 3
[junit4] 2> 2430190 INFO (qtp2127796789-48837) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2 (1552163611727626240)]} 0 3
[junit4] 2> 2430195 INFO (qtp634849440-48852) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-3 (1552163611733917696)]} 0 0
[junit4] 2> 2430195 INFO (qtp634849440-48848) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-3 (1552163611733917697)]} 0 0
[junit4] 2> 2430195 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3 (1552163611733917697)]} 0 2
[junit4] 2> 2430195 INFO (qtp2127796789-48843) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3 (1552163611733917696)]} 0 2
[junit4] 2> 2430200 INFO (qtp634849440-48846) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-1 (-1552163611739160577)]} 0 0
[junit4] 2> 2430200 INFO (qtp634849440-48847) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-1 (-1552163611739160576)]} 0 1
[junit4] 2> 2430200 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-1 (-1552163611739160577)]} 0 3
[junit4] 2> 2430200 INFO (qtp2127796789-48840) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-1 (-1552163611739160576)]} 0 3
[junit4] 2> 2430205 INFO (qtp634849440-48853) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-4 (1552163611744403457)]} 0 0
[junit4] 2> 2430205 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-4 (1552163611744403456)]} 0 1
[junit4] 2> 2430205 INFO (qtp2127796789-48841) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4 (1552163611744403457)]} 0 3
[junit4] 2> 2430206 INFO (qtp2127796789-48836) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4 (1552163611744403456)]} 0 3
[junit4] 2> 2430212 INFO (qtp634849440-48852) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-2 (-1552163611750694913)]} 0 1
[junit4] 2> 2430212 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-2 (-1552163611750694912)]} 0 1
[junit4] 2> 2430212 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-2 (-1552163611750694913)]} 0 3
[junit4] 2> 2430212 INFO (qtp2127796789-48837) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-2 (-1552163611750694912)]} 0 3
[junit4] 2> 2430218 INFO (qtp634849440-48848) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-5 (1552163611758034944)]} 0 1
[junit4] 2> 2430218 INFO (qtp634849440-48846) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-5 (1552163611758034945)]} 0 1
[junit4] 2> 2430218 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5 (1552163611758034945)]} 0 3
[junit4] 2> 2430218 INFO (qtp2127796789-48843) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5 (1552163611758034944)]} 0 3
[junit4] 2> 2430225 INFO (qtp634849440-48847) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-6 (1552163611764326400)]} 0 1
[junit4] 2> 2430225 INFO (qtp634849440-48853) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-6 (1552163611764326401)]} 0 1
[junit4] 2> 2430225 INFO (qtp2127796789-48841) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6 (1552163611764326401)]} 0 3
[junit4] 2> 2430225 INFO (qtp2127796789-48840) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6 (1552163611764326400)]} 0 4
[junit4] 2> 2430226 INFO (OverseerCollectionConfigSetProcessor-97010225271144454-127.0.0.1:46673_solr-n_0000000000) [n:127.0.0.1:46673_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2430231 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-4 (-1552163611770617856)]} 0 1
[junit4] 2> 2430231 INFO (qtp634849440-48852) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-4 (-1552163611771666432)]} 0 1
[junit4] 2> 2430232 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-4 (-1552163611771666432)]} 0 3
[junit4] 2> 2430232 INFO (qtp2127796789-48836) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-4 (-1552163611770617856)]} 0 4
[junit4] 2> 2430236 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-7 (1552163611777957888)]} 0 1
[junit4] 2> 2430237 INFO (qtp634849440-48848) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-7 (1552163611777957889)]} 0 1
[junit4] 2> 2430237 INFO (qtp2127796789-48837) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7 (1552163611777957888)]} 0 3
[junit4] 2> 2430237 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7 (1552163611777957889)]} 0 3
[junit4] 2> 2430246 INFO (qtp634849440-48846) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-8 (1552163611787395073)]} 0 0
[junit4] 2> 2430246 INFO (qtp634849440-48847) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-8 (1552163611787395072)]} 0 0
[junit4] 2> 2430246 INFO (qtp2127796789-48843) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8 (1552163611787395072)]} 0 3
[junit4] 2> 2430246 INFO (qtp2127796789-48841) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8 (1552163611787395073)]} 0 3
[junit4] 2> 2430255 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-8 (-1552163611794735104)]} 0 1
[junit4] 2> 2430256 INFO (qtp634849440-48853) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-8 (-1552163611795783680)]} 0 3
[junit4] 2> 2430256 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-8 (-1552163611795783680)]} 0 5
[junit4] 2> 2430257 INFO (qtp2127796789-48840) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-8 (-1552163611794735104)]} 0 6
[junit4] 2> 2430261 INFO (qtp634849440-48852) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-9 (1552163611803123712)]} 0 1
[junit4] 2> 2430261 INFO (qtp2127796789-48836) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9 (1552163611803123712)]} 0 3
[junit4] 2> 2430262 INFO (qtp634849440-48850) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-9 (1552163611804172288)]} 0 1
[junit4] 2> 2430262 INFO (qtp2127796789-48837) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9 (1552163611804172288)]} 0 3
[junit4] 2> 2430267 INFO (qtp634849440-48848) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-10 (1552163611809415168)]} 0 0
[junit4] 2> 2430267 INFO (qtp634849440-48846) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-10 (1552163611809415169)]} 0 1
[junit4] 2> 2430267 INFO (qtp2127796789-48839) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10 (1552163611809415168)]} 0 3
[junit4] 2> 2430267 INFO (qtp2127796789-48843) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10 (1552163611809415169)]} 0 3
[junit4] 2> 2430273 INFO (qtp634849440-48851) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-11 (1552163611815706624)]} 0 0
[junit4] 2> 2430273 INFO (qtp634849440-48847) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-11 (1552163611815706625)]} 0 1
[junit4] 2> 2430273 INFO (qtp2127796789-48842) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11 (1552163611815706625)]} 0 3
[junit4] 2> 2430273 INFO (qtp2127796789-48841) [n:127.0.0.1:46673_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11 (1552163611815706624)]} 0 3
[junit4] 2> 2430278 INFO (qtp634849440-48853) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:46673/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-11 (-1552163611821998081)]} 0 0
[junit4] 2> 2430279 INFO (qtp634849440-48852) [n:127.0.0.1:48362_solr c:recoverytest s:shard1 r:core_
[...truncated too long message...]
ckmanagement.BlocksMap.size(BlocksMap.java:203)
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3370)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:5729)
[junit4] 2> ... 54 more
[junit4] 2> 2442458 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33037 33037
[junit4] 2> 2442459 INFO (SUITE-HdfsRecoveryZkTest-seed#[8B11045FDE87FCC5]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=zh-SG, timezone=Australia/NSW
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=2,free=302813440,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestPKIAuthenticationPlugin, TestDocumentBuilder, ResponseHeaderTest, TestShardHandlerFactory, TestOrdValues, TestSolrConfigHandlerConcurrent, IndexBasedSpellCheckerTest, TestRandomRequestDistribution, TestManagedSchemaAPI, TestSolrCloudSnapshots, TestConfigReload, TestFieldCacheVsDocValues, HdfsUnloadDistributedZkTest, TestPhraseSuggestions, VersionInfoTest, ShardRoutingTest, TestHashPartitioner, TestCustomDocTransformer, HighlighterTest, CollectionsAPIAsyncDistributedZkTest, TestUpdate, TestComplexPhraseQParserPlugin, TestTrackingShardHandlerFactory, HardAutoCommitTest, RestartWhileUpdatingTest, TestUseDocValuesAsStored2, TestStressReorder, TestComponentsName, TestConfigOverlay, HdfsCollectionsAPIDistributedZkTest, CdcrUpdateLogTest, TestSchemaNameResource, SolrCoreTest, SampleTest, TestLeaderElectionWithEmptyReplica, HttpPartitionTest, TestCryptoKeys, TestDistributedSearch, DistribDocExpirationUpdateProcessorTest, PrimitiveFieldTypeTest, TestSolrIndexConfig, CurrencyFieldXmlFileTest, SpatialHeatmapFacetsTest, TestLeaderInitiatedRecoveryThread, ReplicaListTransformerTest, TestStressRecovery, TestOverriddenPrefixQueryForCustomFieldType, ResponseLogComponentTest, BJQParserTest, TestXmlQParserPlugin, RecoveryZkTest, TestTolerantUpdateProcessorRandomCloud, DisMaxRequestHandlerTest, ConcurrentDeleteAndCreateCollectionTest, TestStressLiveNodes, SolrTestCaseJ4Test, RulesTest, TestNamedUpdateProcessors, DirectSolrConnectionTest, TestPseudoReturnFields, TestExclusionRuleCollectionAccess, SuggestComponentTest, SegmentsInfoRequestHandlerTest, TestJettySolrRunner, TestExactSharedStatsCache, CoreSorterTest, InfoHandlerTest, ZkNodePropsTest, TestInfoStreamLogging, TimeZoneUtilsTest, XsltUpdateRequestHandlerTest, TestInitQParser, FastVectorHighlighterTest, TestScoreJoinQPScore, ShardSplitTest, CdcrRequestHandlerTest, HdfsRestartWhileUpdatingTest, TestMissingGroups, TestPartialUpdateDeduplication, TestRemoteStreaming, NumericFieldsTest, TestTrieFacet, HdfsThreadLeakTest, OutputWriterTest, MergeStrategyTest, TestAnalyzedSuggestions, AlternateDirectoryTest, HdfsDirectoryTest, TestBinaryResponseWriter, DOMUtilTest, TestCloudDeleteByQuery, AssignTest, SolrRequestParserTest, BadComponentTest, TestDocTermOrds, DistributedFacetExistsSmallTest, PeerSyncTest, ZkStateReaderTest, XmlUpdateRequestHandlerTest, DistributedSuggestComponentTest, TestCollectionAPI, AnalyticsQueryTest, TestSerializedLuceneMatchVersion, FileUtilsTest, TermsComponentTest, SynonymTokenizerTest, TestCursorMarkWithoutUniqueKey, ZkCLITest, SOLR749Test, SharedFSAutoReplicaFailoverUtilsTest, DeleteStatusTest, TestReplicaProperties, DistributedFacetPivotLongTailTest, LeaderFailoverAfterPartitionTest, TestFieldTypeCollectionResource, TestCloudPivotFacet, TestSlowCompositeReaderWrapper, TestCharFilters, TestRTGBase, StatelessScriptUpdateProcessorFactoryTest, DistributedQueueTest, SolrPluginUtilsTest, TestGeoJSONResponseWriter, PluginInfoTest, TestJsonFacets, TestFaceting, TestAnalyzeInfixSuggestions, ExplicitHLLTest, TestSolrDynamicMBean, TestBM25SimilarityFactory, TestLRUStatsCache, DirectUpdateHandlerTest, TestDynamicFieldCollectionResource, JSONWriterTest, SimplePostToolTest, PolyFieldTest, SortSpecParsingTest, TestDistribDocBasedVersion, CursorPagingTest, CloudExitableDirectoryReaderTest, TestExpandComponent, TestHighFrequencyDictionaryFactory, TestObjectReleaseTracker, TestStressLucene, TestReplicationHandlerBackup, TestSubQueryTransformer, CloudMLTQParserTest, HighlighterMaxOffsetTest, CheckHdfsIndexTest, PeerSyncWithIndexFingerprintCachingTest, TestSha256AuthenticationProvider, SuggesterFSTTest, TestRandomDVFaceting, TestSweetSpotSimilarityFactory, SolrCLIZkUtilsTest, MoreLikeThisHandlerTest, HLLSerializationTest, ChangedSchemaMergeTest, TestRawResponseWriter, TestSolrCloudWithSecureImpersonation, TestFunctionQuery, RecoveryAfterSoftCommitTest, TestZkChroot, ShardRoutingCustomTest, AutoCommitTest, TestDistributedGrouping, ZkControllerTest, TestJoin, TestReload, DistributedTermsComponentTest, TestCoreContainer, SimpleFacetsTest, TestGroupingSearch, BadIndexSchemaTest, TestSort, TestFiltering, TestIndexSearcher, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, TestExtendedDismaxParser, DocValuesTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, DocValuesMultiTest, TestSurroundQueryParser, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, RequiredFieldsTest, TestSolrQueryParser, IndexSchemaRuntimeFieldTest, RegexBoostProcessorTest, TestCollationField, ReturnFieldsTest, MBeansHandlerTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestLFUCache, TestLuceneMatchVersion, EchoParamsTest, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestJmxMonitoredMap, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, BaseCdcrDistributedZkTest, CdcrBootstrapTest, ConnectionManagerTest, CustomCollectionTest, DistribJoinFromCollectionTest, DistributedVersionInfoTest, LeaderFailureAfterFreshStartTest, LeaderInitiatedRecoveryOnCommitTest, MigrateRouteKeyTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverriddenZkACLAndCredentialsProvidersTest, OverseerCollectionConfigSetProcessorTest, OverseerStatusTest, OverseerTaskQueueTest, RemoteQueryErrorTest, ReplaceNodeTest, RollingRestartTest, SSLMigrationTest, SaslZkACLProviderTest, SolrXmlInZkTest, TestCloudInspectUtil, TestCloudPseudoReturnFields, TestCloudRecovery, TestLocalFSCloudBackupRestore, TestRandomFlRTGCloud, TestRequestStatusCollectionAPI, TestSolrCloudWithDelegationTokens, TestSolrCloudWithKerberosAlt, TriLevelCompositeIdRoutingTest, HdfsRecoveryZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HdfsRecoveryZkTest -Dtests.seed=8B11045FDE87FCC5 -Dtests.slow=true -Dtests.locale=zh-SG -Dtests.timezone=Australia/NSW -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | HdfsRecoveryZkTest (suite) <<<
[junit4] > Throwable #1: java.lang.AssertionError: ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog]
[junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43)
[junit4] > at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
[junit4] > at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
[junit4] > at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102)
[junit4] > at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[junit4] > at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:705)
[junit4] > at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:767)
[junit4] > at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1006)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:871)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:775)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:842)
[junit4] > at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:498)
[junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > at __randomizedtesting.SeedInfo.seed([8B11045FDE87FCC5]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:260)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [519/658 (2!)] on J0 in 50.43s, 1 test, 1 failure <<< FAILURES!
[...truncated 11501 lines...]
-validate-source-patterns:
[source-patterns] nocommit: solr/core/src/test/org/apache/solr/cloud/DocValuesNotIndexedTest.java
BUILD FAILED
/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/build.xml:765: The following error occurred while executing this line:
/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/build.xml:130: Found 1 violations in source files (nocommit).
Total time: 90 minutes 13 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any