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/12/19 15:29:56 UTC
[JENKINS] Lucene-Solr-6.x-Solaris (64bit/jdk1.8.0) - Build # 560 -
Still unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Solaris/560/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
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.GeneratedConstructorAccessor102.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:704) at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766) at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774) 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.GeneratedConstructorAccessor102.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:704)
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766)
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774)
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([AB2AB2C2DA355053]: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:266)
at sun.reflect.GeneratedMethodAccessor30.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 12393 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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/init-core-data-001
[junit4] 2> 2506117 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-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> 2506118 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/tempDir-001
[junit4] 2> 2506119 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2506119 INFO (Thread-8615) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2506119 INFO (Thread-8615) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2506219 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37466
[junit4] 2> 2506233 INFO (jetty-launcher-9391-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2506233 INFO (jetty-launcher-9391-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2506234 INFO (jetty-launcher-9391-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4b942ed0{/solr,null,AVAILABLE}
[junit4] 2> 2506235 INFO (jetty-launcher-9391-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1f30322b{SSL,[ssl, http/1.1]}{127.0.0.1:54660}
[junit4] 2> 2506235 INFO (jetty-launcher-9391-thread-2) [ ] o.e.j.s.Server Started @2510470ms
[junit4] 2> 2506235 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54660}
[junit4] 2> 2506235 ERROR (jetty-launcher-9391-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2506236 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2506236 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2506236 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2506236 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-19T15:03:21.258Z
[junit4] 2> 2506239 INFO (jetty-launcher-9391-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1c1c4ad6{/solr,null,AVAILABLE}
[junit4] 2> 2506240 INFO (jetty-launcher-9391-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3e318b62{SSL,[ssl, http/1.1]}{127.0.0.1:52909}
[junit4] 2> 2506240 INFO (jetty-launcher-9391-thread-1) [ ] o.e.j.s.Server Started @2510475ms
[junit4] 2> 2506240 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52909}
[junit4] 2> 2506240 ERROR (jetty-launcher-9391-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2506240 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 2506241 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2506241 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2506241 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-19T15:03:21.263Z
[junit4] 2> 2506247 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2506247 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2506258 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2506259 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2506259 INFO (jetty-launcher-9391-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37466/solr
[junit4] 2> 2506260 INFO (jetty-launcher-9391-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37466/solr
[junit4] 2> 2506311 INFO (jetty-launcher-9391-thread-1) [n:127.0.0.1:52909_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52909_solr
[junit4] 2> 2506313 INFO (jetty-launcher-9391-thread-1) [n:127.0.0.1:52909_solr ] o.a.s.c.Overseer Overseer (id=97134824727707654-127.0.0.1:52909_solr-n_0000000000) starting
[junit4] 2> 2506313 INFO (jetty-launcher-9391-thread-2) [n:127.0.0.1:54660_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54660_solr
[junit4] 2> 2506318 INFO (zkCallback-9402-thread-1-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2506319 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2506329 INFO (jetty-launcher-9391-thread-1) [n:127.0.0.1:52909_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52909_solr
[junit4] 2> 2506331 INFO (zkCallback-9402-thread-1-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2506346 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2506427 INFO (jetty-launcher-9391-thread-2) [n:127.0.0.1:54660_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/tempDir-001/node2/.
[junit4] 2> 2506492 INFO (jetty-launcher-9391-thread-1) [n:127.0.0.1:52909_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/tempDir-001/node1/.
[junit4] 2> 2506499 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x159179bc3370007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2506530 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2506532 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37466/solr ready
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 2506586 WARN (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 2506598 WARN (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2506601 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2506622 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-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_64907_hdfs____.9opxws/webapp
[junit4] 2> 2508280 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@solaris-vm:64907
[junit4] 2> 2508477 WARN (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2508478 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2508500 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-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_63988_datanode____96xz43/webapp
[junit4] 2> 2509049 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:63988
[junit4] 2> 2509137 WARN (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2509138 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2509179 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-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_47622_datanode____666mm2/webapp
[junit4] 2> 2509221 INFO (IPC Server handler 3 on 35997) [ ] BlockStateChange BLOCK* processReport: from storage DS-2967eede-3e3a-4c6f-ac5c-b3422102455f node DatanodeRegistration(127.0.0.1:33027, datanodeUuid=dc4a6456-d7a6-4cf0-81cc-1817067525b1, infoPort=60374, infoSecurePort=0, ipcPort=40004, storageInfo=lv=-56;cid=testClusterID;nsid=935650325;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2509221 INFO (IPC Server handler 3 on 35997) [ ] BlockStateChange BLOCK* processReport: from storage DS-5af795bd-887f-46c1-8412-77369bd1662c node DatanodeRegistration(127.0.0.1:33027, datanodeUuid=dc4a6456-d7a6-4cf0-81cc-1817067525b1, infoPort=60374, infoSecurePort=0, ipcPort=40004, storageInfo=lv=-56;cid=testClusterID;nsid=935650325;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2512785 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:47622
[junit4] 2> 2512899 INFO (IPC Server handler 4 on 35997) [ ] BlockStateChange BLOCK* processReport: from storage DS-5c603127-a1b8-4349-904f-55a61182b128 node DatanodeRegistration(127.0.0.1:56611, datanodeUuid=6d6b8e2e-f3d5-4145-827a-5d3b047c59a1, infoPort=43606, infoSecurePort=0, ipcPort=64632, storageInfo=lv=-56;cid=testClusterID;nsid=935650325;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2512900 INFO (IPC Server handler 4 on 35997) [ ] BlockStateChange BLOCK* processReport: from storage DS-efffe18c-aef2-41e1-89f0-1abb2fa9ee43 node DatanodeRegistration(127.0.0.1:56611, datanodeUuid=6d6b8e2e-f3d5-4145-827a-5d3b047c59a1, infoPort=43606, infoSecurePort=0, ipcPort=64632, storageInfo=lv=-56;cid=testClusterID;nsid=935650325;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2512990 INFO (TEST-HdfsRecoveryZkTest.test-seed#[AB2AB2C2DA355053]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 2513012 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_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> 2513016 INFO (OverseerThreadFactory-9896-thread-1-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_solr ] o.a.s.c.CreateCollectionCmd Create collection recoverytest
[junit4] 2> 2513135 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_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> 2513154 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_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> 2513261 INFO (zkCallback-9402-thread-1-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_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> 2513261 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_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> 2514152 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2514159 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema [recoverytest_shard1_replica2] Schema name=minimal
[junit4] 2> 2514161 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_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> 2514163 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_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> 2514166 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 2514171 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:35997/data
[junit4] 2> 2514171 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2514171 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/tempDir-001/node1/recoverytest_shard1_replica2], dataDir=[hdfs://solaris-vm:35997/data/recoverytest/core_node1/data/]
[junit4] 2> 2514171 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node1/data/snapshot_metadata
[junit4] 2> 2514173 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema [recoverytest_shard1_replica1] Schema name=minimal
[junit4] 2> 2514176 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_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> 2514177 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_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> 2514177 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:35997/data
[junit4] 2> 2514177 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2514177 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_AB2AB2C2DA355053-001/tempDir-001/node2/recoverytest_shard1_replica1], dataDir=[hdfs://solaris-vm:35997/data/recoverytest/core_node2/data/]
[junit4] 2> 2514178 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node2/data/snapshot_metadata
[junit4] 2> 2514180 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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> 2514180 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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> 2514180 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2514185 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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> 2514185 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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> 2514185 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2514293 WARN (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2514295 WARN (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2519294 WARN (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2519295 WARN (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2524301 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2524303 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2524304 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node1/data
[junit4] 2> 2524304 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node2/data
[junit4] 2> 2524325 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node1/data/index
[junit4] 2> 2524326 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:35997/data/recoverytest/core_node2/data/index
[junit4] 2> 2524333 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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> 2524333 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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> 2524333 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2524336 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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> 2524337 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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> 2524337 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2524425 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2524429 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2524534 INFO (IPC Server handler 2 on 35997) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33027 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-efffe18c-aef2-41e1-89f0-1abb2fa9ee43:NORMAL:127.0.0.1:56611|RBW], ReplicaUC[[DISK]DS-5af795bd-887f-46c1-8412-77369bd1662c:NORMAL:127.0.0.1:33027|RBW]]} size 0
[junit4] 2> 2524535 INFO (IPC Server handler 9 on 35997) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:56611 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-5af795bd-887f-46c1-8412-77369bd1662c:NORMAL:127.0.0.1:33027|RBW], ReplicaUC[[DISK]DS-5c603127-a1b8-4349-904f-55a61182b128:NORMAL:127.0.0.1:56611|FINALIZED]]} size 0
[junit4] 2> 2524535 INFO (IPC Server handler 5 on 35997) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:56611 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-2967eede-3e3a-4c6f-ac5c-b3422102455f:NORMAL:127.0.0.1:33027|RBW], ReplicaUC[[DISK]DS-efffe18c-aef2-41e1-89f0-1abb2fa9ee43:NORMAL:127.0.0.1:56611|RBW]]} size 0
[junit4] 2> 2524537 INFO (IPC Server handler 0 on 35997) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:33027 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-2967eede-3e3a-4c6f-ac5c-b3422102455f:NORMAL:127.0.0.1:33027|RBW], ReplicaUC[[DISK]DS-efffe18c-aef2-41e1-89f0-1abb2fa9ee43:NORMAL:127.0.0.1:56611|RBW]]} size 0
[junit4] 2> 2524565 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2524565 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2524565 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2524570 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2524570 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2524570 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2524584 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2524584 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2524588 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2524588 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2524602 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@4a8486a3[recoverytest_shard1_replica2] main]
[junit4] 2> 2524604 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2524605 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2524606 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2524606 INFO (searcherExecutor-9901-thread-1-processing-n:127.0.0.1:52909_solr x:recoverytest_shard1_replica2 s:shard1 c:recoverytest) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SolrCore [recoverytest_shard1_replica2] Registered new searcher Searcher@4a8486a3[recoverytest_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2524606 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@66bfe60e[recoverytest_shard1_replica1] main]
[junit4] 2> 2524606 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554157215026249728
[junit4] 2> 2524608 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2524608 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2524608 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2524609 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554157215029395456
[junit4] 2> 2524609 INFO (searcherExecutor-9902-thread-1-processing-n:127.0.0.1:54660_solr x:recoverytest_shard1_replica1 s:shard1 c:recoverytest) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.SolrCore [recoverytest_shard1_replica1] Registered new searcher Searcher@66bfe60e[recoverytest_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2524620 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2524620 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2524620 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/
[junit4] 2> 2524621 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica2 url=https://127.0.0.1:52909/solr START replicas=[https://127.0.0.1:54660/solr/recoverytest_shard1_replica1/] nUpdates=100
[junit4] 2> 2524621 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica2 url=https://127.0.0.1:52909/solr DONE. We have no versions. sync failed.
[junit4] 2> 2524622 INFO (zkCallback-9402-thread-5-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_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> 2524625 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_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> 2524631 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.S.Request [recoverytest_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2524632 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2524632 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2524642 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/ shard1
[junit4] 2> 2524749 INFO (zkCallback-9402-thread-4-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_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> 2524749 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_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> 2524794 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2524798 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 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=11669
[junit4] 2> 2524901 INFO (zkCallback-9402-thread-4-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_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> 2524902 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_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> 2525626 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 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=12479
[junit4] 2> 2525632 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_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> 2525738 INFO (zkCallback-9402-thread-5-processing-n:127.0.0.1:52909_solr) [n:127.0.0.1:52909_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> 2525738 INFO (zkCallback-9401-thread-1-processing-n:127.0.0.1:54660_solr) [n:127.0.0.1:54660_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> 2526634 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_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=13628
[junit4] 2> 2526635 INFO (TEST-HdfsRecoveryZkTest.test-seed#[AB2AB2C2DA355053]) [ ] o.a.s.c.RecoveryZkTest Indexing 1350 documents
[junit4] 2> 2526665 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-0 (1554157217160101888)]} 0 15
[junit4] 2> 2526666 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0 (1554157217160101888)]} 0 25
[junit4] 2> 2526666 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-0 (1554157217162199040)]} 0 15
[junit4] 2> 2526667 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0 (1554157217162199040)]} 0 23
[junit4] 2> 2526672 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-1 (1554157217190510592)]} 0 0
[junit4] 2> 2526672 INFO (qtp1708883334-46263) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-1 (1554157217188413440)]} 0 1
[junit4] 2> 2526673 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1 (1554157217190510592)]} 0 3
[junit4] 2> 2526673 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1 (1554157217188413440)]} 0 4
[junit4] 2> 2526678 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-2 (1554157217195753473)]} 0 1
[junit4] 2> 2526678 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-2 (1554157217195753472)]} 0 1
[junit4] 2> 2526679 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2 (1554157217195753473)]} 0 3
[junit4] 2> 2526679 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2 (1554157217195753472)]} 0 3
[junit4] 2> 2526687 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-3 (1554157217202044928)]} 0 2
[junit4] 2> 2526688 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3 (1554157217202044928)]} 0 6
[junit4] 2> 2526689 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-3 (1554157217202044929)]} 0 1
[junit4] 2> 2526689 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3 (1554157217202044929)]} 0 8
[junit4] 2> 2526698 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-2 (-1554157217214627840)]} 0 1
[junit4] 2> 2526699 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-2 (-1554157217214627841)]} 0 2
[junit4] 2> 2526699 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-2 (-1554157217214627841)]} 0 6
[junit4] 2> 2526700 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-2 (-1554157217214627840)]} 0 6
[junit4] 2> 2526707 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-4 (1554157217225113600)]} 0 1
[junit4] 2> 2526707 INFO (qtp1708883334-46263) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-4 (1554157217224065024)]} 0 1
[junit4] 2> 2526707 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4 (1554157217225113600)]} 0 4
[junit4] 2> 2526708 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4 (1554157217224065024)]} 0 5
[junit4] 2> 2526715 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-5 (1554157217232453632)]} 0 1
[junit4] 2> 2526715 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-5 (1554157217232453633)]} 0 1
[junit4] 2> 2526715 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5 (1554157217232453633)]} 0 5
[junit4] 2> 2526715 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5 (1554157217232453632)]} 0 5
[junit4] 2> 2526721 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-6 (1554157217240842241)]} 0 1
[junit4] 2> 2526721 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-6 (1554157217240842240)]} 0 1
[junit4] 2> 2526722 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6 (1554157217240842240)]} 0 3
[junit4] 2> 2526722 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6 (1554157217240842241)]} 0 3
[junit4] 2> 2526728 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-7 (1554157217248182273)]} 0 1
[junit4] 2> 2526728 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7 (1554157217248182273)]} 0 3
[junit4] 2> 2526729 INFO (qtp1708883334-46263) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-7 (1554157217248182272)]} 0 1
[junit4] 2> 2526729 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7 (1554157217248182272)]} 0 4
[junit4] 2> 2526733 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-4 (-1554157217253425152)]} 0 1
[junit4] 2> 2526734 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-4 (-1554157217253425152)]} 0 3
[junit4] 2> 2526734 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-4 (-1554157217254473728)]} 0 1
[junit4] 2> 2526735 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-4 (-1554157217254473728)]} 0 3
[junit4] 2> 2526743 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-8 (1554157217260765184)]} 0 1
[junit4] 2> 2526743 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-8 (1554157217260765185)]} 0 1
[junit4] 2> 2526743 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8 (1554157217260765185)]} 0 6
[junit4] 2> 2526743 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8 (1554157217260765184)]} 0 6
[junit4] 2> 2526749 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-5 (-1554157217269153792)]} 0 1
[junit4] 2> 2526750 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-5 (-1554157217269153792)]} 0 4
[junit4] 2> 2526751 INFO (qtp1708883334-46263) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-5 (-1554157217270202368)]} 0 2
[junit4] 2> 2526752 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-5 (-1554157217270202368)]} 0 6
[junit4] 2> 2526755 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-9 (1554157217276493824)]} 0 1
[junit4] 2> 2526755 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9 (1554157217276493824)]} 0 3
[junit4] 2> 2526758 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-9 (1554157217278590976)]} 0 1
[junit4] 2> 2526758 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9 (1554157217278590976)]} 0 3
[junit4] 2> 2526760 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-6 (-1554157217281736704)]} 0 0
[junit4] 2> 2526760 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-6 (-1554157217281736704)]} 0 2
[junit4] 2> 2526764 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-6 (-1554157217285931008)]} 0 1
[junit4] 2> 2526764 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-6 (-1554157217285931008)]} 0 3
[junit4] 2> 2526767 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-10 (1554157217288028160)]} 0 1
[junit4] 2> 2526769 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10 (1554157217288028160)]} 0 5
[junit4] 2> 2526769 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-10 (1554157217291173888)]} 0 1
[junit4] 2> 2526770 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10 (1554157217291173888)]} 0 3
[junit4] 2> 2526773 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-8 (-1554157217296416768)]} 0 1
[junit4] 2> 2526774 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-8 (-1554157217296416768)]} 0 3
[junit4] 2> 2526778 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-8 (-1554157217297465344)]} 0 2
[junit4] 2> 2526778 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-8 (-1554157217297465344)]} 0 6
[junit4] 2> 2526780 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-11 (1554157217302708224)]} 0 1
[junit4] 2> 2526780 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11 (1554157217302708224)]} 0 3
[junit4] 2> 2526784 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-11 (1554157217306902528)]} 0 1
[junit4] 2> 2526784 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11 (1554157217306902528)]} 0 3
[junit4] 2> 2526787 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-9 (-1554157217308999680)]} 0 1
[junit4] 2> 2526787 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-9 (-1554157217308999680)]} 0 3
[junit4] 2> 2526790 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-9 (-1554157217312145408)]} 0 1
[junit4] 2> 2526790 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-9 (-1554157217312145408)]} 0 3
[junit4] 2> 2526792 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-12 (1554157217316339712)]} 0 1
[junit4] 2> 2526793 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-12 (1554157217316339712)]} 0 3
[junit4] 2> 2526795 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-12 (1554157217318436864)]} 0 0
[junit4] 2> 2526795 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-12 (1554157217318436864)]} 0 3
[junit4] 2> 2526798 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-13 (1554157217321582592)]} 0 1
[junit4] 2> 2526799 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-13 (1554157217321582592)]} 0 4
[junit4] 2> 2526800 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-13 (1554157217323679744)]} 0 1
[junit4] 2> 2526801 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-13 (1554157217323679744)]} 0 3
[junit4] 2> 2526805 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-14 (1554157217328922624)]} 0 1
[junit4] 2> 2526805 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-14 (1554157217328922624)]} 0 3
[junit4] 2> 2526807 INFO (qtp1708883334-46265) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-14 (1554157217331019776)]} 0 1
[junit4] 2> 2526807 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-14 (1554157217331019776)]} 0 3
[junit4] 2> 2526810 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-10 (-1554157217334165504)]} 0 1
[junit4] 2> 2526811 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-10 (-1554157217334165504)]} 0 3
[junit4] 2> 2526812 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-10 (-1554157217336262656)]} 0 0
[junit4] 2> 2526812 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-10 (-1554157217336262656)]} 0 2
[junit4] 2> 2526817 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-15 (1554157217341505536)]} 0 1
[junit4] 2> 2526818 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-15 (1554157217341505536)]} 0 4
[junit4] 2> 2526819 INFO (qtp1708883334-46263) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-15 (1554157217341505537)]} 0 1
[junit4] 2> 2526819 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-15 (1554157217341505537)]} 0 4
[junit4] 2> 2526823 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-13 (-1554157217347796992)]} 0 0
[junit4] 2> 2526823 INFO (qtp1149546374-46283) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-13 (-1554157217347796992)]} 0 2
[junit4] 2> 2526824 INFO (qtp1708883334-46262) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-13 (-1554157217348845568)]} 0 0
[junit4] 2> 2526825 INFO (qtp1149546374-46275) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-13 (-1554157217348845568)]} 0 3
[junit4] 2> 2526829 INFO (qtp1708883334-46266) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-16 (1554157217353039872)]} 0 1
[junit4] 2> 2526829 INFO (qtp1149546374-46276) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-16 (1554157217353039872)]} 0 4
[junit4] 2> 2526830 INFO (qtp1708883334-46260) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-16 (1554157217355137024)]} 0 1
[junit4] 2> 2526830 INFO (qtp1149546374-46274) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-16 (1554157217355137024)]} 0 3
[junit4] 2> 2526834 INFO (qtp1708883334-46259) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-17 (1554157217360379904)]} 0 0
[junit4] 2> 2526835 INFO (qtp1149546374-46285) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-17 (1554157217360379904)]} 0 3
[junit4] 2> 2526837 INFO (qtp1708883334-46264) [n:127.0.0.1:54660_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52909/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-17 (1554157217361428480)]} 0 1
[junit4] 2> 2526838 INFO (qtp1149546374-46278) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-17 (1554157217361428480)]} 0 5
[junit4] 2> 2526842 ERROR (updateExecutor-9397-thread-1-processing-https:////127.0.0.1:54660//solr//recoverytest_shard1_replica1 x:recoverytest_shard1_replica2 r:core_node1 n:127.0.0.1:52909_solr s:shard1 c:recoverytest) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.StreamingSolrClients error
[junit4] 2> org.apache.http.NoHttpResponseException: 127.0.0.1:54660 failed to respond
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
[junit4] 2> at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] 2> at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.sendUpdateStream(ConcurrentUpdateSolrClient.java:311)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.run(ConcurrentUpdateSolrClient.java:184)
[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> 2526844 WARN (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.DistributedUpdateProcessor Error sending update to https://127.0.0.1:54660/solr
[junit4] 2> org.apache.http.NoHttpResponseException: 127.0.0.1:54660 failed to respond
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
[junit4] 2> at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] 2> at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.sendUpdateStream(ConcurrentUpdateSolrClient.java:311)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.run(ConcurrentUpdateSolrClient.java:184)
[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> 2526844 ERROR (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.DistributedUpdateProcessor Setting up to try to start recovery on replica https://127.0.0.1:54660/solr/recoverytest_shard1_replica1/
[junit4] 2> org.apache.http.NoHttpResponseException: 127.0.0.1:54660 failed to respond
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:143)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
[junit4] 2> at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] 2> at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] 2> at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
[junit4] 2> at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
[junit4] 2> at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.sendUpdateStream(ConcurrentUpdateSolrClient.java:311)
[junit4] 2> at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrClient$Runner.run(ConcurrentUpdateSolrClient.java:184)
[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> 2526844 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.ZkController Put replica core=recoverytest_shard1_replica1 coreNodeName=core_node2 on 127.0.0.1:54660_solr into leader-initiated recovery.
[junit4] 2> 2526845 INFO (qtp1149546374-46284) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-18 (1554157217365622784)]} 0 7
[junit4] 2> 2526845 INFO (TEST-HdfsRecoveryZkTest.test-seed#[AB2AB2C2DA355053]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1f30322b{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 2526852 INFO (updateExecutor-9397-thread-1-processing-x:recoverytest_shard1_replica2 r:core_node1 https:////127.0.0.1:54660//solr//recoverytest_shard1_replica1// n:127.0.0.1:52909_solr s:shard1 c:recoverytest) [n:127.0.0.1:52909_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.LeaderInitiatedRecoveryThread Put replica core=recoverytest_shard1_replica1 coreNodeName=core_node2 on 127.0.0.1:54660_solr into leader-initiated recovery.
[junit4] 2> 2526852 WARN (updateExecutor-9397-thread-1-proc
[...truncated too long message...]
java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.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> 2539809 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37466 37466
[junit4] 2> 2539810 INFO (SUITE-HdfsRecoveryZkTest-seed#[AB2AB2C2DA355053]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {rnd_b=Lucene50(blocksize=128), _version_=PostingsFormat(name=LuceneVarGapDocFreqInterval), a_t=PostingsFormat(name=LuceneVarGapDocFreqInterval), a_i=Lucene50(blocksize=128), id=Lucene50(blocksize=128)}, docValues:{}, maxPointsInLeafNode=2008, maxMBSortInHeap=7.968954124163064, sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=es-CO, timezone=Africa/Windhoek
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_112 (64-bit)/cpus=3,threads=2,free=223475544,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [LeaderInitiatedRecoveryOnShardRestartTest, DefaultValueUpdateProcessorTest, TestIndexingPerformance, CollectionTooManyReplicasTest, MBeansHandlerTest, TestSchemaSimilarityResource, SolrIndexSplitterTest, TestFieldCacheSortRandom, TestSSLRandomization, TestHdfsUpdateLog, ExitableDirectoryReaderTest, TestCustomSort, SimpleMLTQParserTest, TestSolrCloudWithDelegationTokens, TestFilteredDocIdSet, CoreSorterTest, EchoParamsTest, MinimalSchemaTest, HighlighterMaxOffsetTest, TestIndexSearcher, DistributedIntervalFacetingTest, TestShortCircuitedRequests, TestStressUserVersions, WordBreakSolrSpellCheckerTest, HdfsThreadLeakTest, SearchHandlerTest, FileBasedSpellCheckerTest, TestDocBasedVersionConstraints, TestSmileRequest, TestSearchPerf, RequestHandlersTest, SolrCoreCheckLockOnStartupTest, TestSolrQueryParser, ZkSolrClientTest, ConvertedLegacyTest, TestSolrDynamicMBean, SmileWriterTest, NotRequiredUniqueKeyTest, TestSchemaNameResource, TestNRTOpen, URLClassifyProcessorTest, TestQueryWrapperFilter, TestManagedStopFilterFactory, TestSolrCloudSnapshots, BinaryUpdateRequestHandlerTest, HdfsRestartWhileUpdatingTest, TestManagedSchemaThreadSafety, ClassificationUpdateProcessorTest, TestAuthenticationFramework, TestTolerantUpdateProcessorRandomCloud, RulesTest, TermVectorComponentDistributedTest, TestMinMaxOnMultiValuedField, TestExactStatsCache, TestLMJelinekMercerSimilarityFactory, SolrCloudExampleTest, TestSolrDeletionPolicy2, TimerUtilsTest, BadCopyFieldTest, ShardRoutingCustomTest, TestLMDirichletSimilarityFactory, TestSuggestSpellingConverter, TestFieldCacheWithThreads, SortByFunctionTest, SimpleCollectionCreateDeleteTest, SpellingQueryConverterTest, BufferStoreTest, CdcrReplicationHandlerTest, SpellPossibilityIteratorTest, ConnectionReuseTest, AnalyticsMergeStrategyTest, TestDistributedGrouping, FieldMutatingUpdateProcessorTest, CursorMarkTest, TestCloudSchemaless, TestCrossCoreJoin, OverriddenZkACLAndCredentialsProvidersTest, LukeRequestHandlerTest, TestSubQueryTransformerDistrib, TestJsonFacetRefinement, TestValueSourceCache, TestConfigOverlay, TestInfoStreamLogging, TestPerFieldSimilarityClassic, AddSchemaFieldsUpdateProcessorFactoryTest, CollectionsAPISolrJTest, TestFuzzyAnalyzedSuggestions, LeaderElectionIntegrationTest, TestSolrCloudWithSecureImpersonation, TestDocSet, CacheHeaderTest, QueryResultKeyTest, TolerantUpdateProcessorTest, TestCloudInspectUtil, TestFiltering, ChangedSchemaMergeTest, HLLUtilTest, DocValuesMissingTest, HdfsBasicDistributedZk2Test, TestShardHandlerFactory, MultiThreadedOCPTest, HdfsChaosMonkeyNothingIsSafeTest, SegmentsInfoRequestHandlerTest, RollingRestartTest, TestConfigReload, TestSerializedLuceneMatchVersion, SpellCheckComponentTest, TestUseDocValuesAsStored, TestRecoveryHdfs, RemoteQueryErrorTest, DistributedFacetPivotSmallTest, LeaderElectionContextKeyTest, AsyncCallRequestStatusResponseTest, StressHdfsTest, BigEndianAscendingWordDeserializerTest, TestRangeQuery, NoCacheHeaderTest, TestHdfsCloudBackupRestore, TestTrie, TestDeleteCollectionOnDownNodes, AutoCommitTest, TemplateUpdateProcessorTest, ConfigSetsAPITest, TestSolrConfigHandlerConcurrent, BlockJoinFacetSimpleTest, TestMaxScoreQueryParser, RAMDirectoryFactoryTest, TestRestoreCore, TestMiniSolrCloudClusterSSL, DeleteShardTest, TestDFISimilarityFactory, TestOmitPositions, FullSolrCloudDistribCmdsTest, TestLocalFSCloudBackupRestore, OverseerModifyCollectionTest, ShowFileRequestHandlerTest, DistributedFacetExistsSmallTest, ClassificationUpdateProcessorFactoryTest, ConjunctionSolrSpellCheckerTest, ResourceLoaderTest, TestCloudManagedSchema, TestLuceneMatchVersion, TestDistribIDF, TestScoreJoinQPNoScore, DistributedQueryComponentCustomSortTest, BitVectorTest, AnalysisErrorHandlingTest, CollectionsAPIDistributedZkTest, ParsingFieldUpdateProcessorsTest, SmileWriterTest, DistributedDebugComponentTest, ExternalFileFieldSortTest, JsonLoaderTest, SpellCheckCollatorTest, TestRTimerTree, CreateCollectionCleanupTest, FieldAnalysisRequestHandlerTest, TestDistributedMissingSort, PreAnalyzedFieldTest, CoreAdminRequestStatusTest, DistributedTermsComponentTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, OpenCloseCoreStressTest, ShardRoutingTest, TestRandomFaceting, TestZkChroot, TestRandomDVFaceting, ZkCLITest, TestDistributedSearch, IndexSchemaTest, TestCollationField, UpdateRequestProcessorFactoryTest, JSONWriterTest, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, TestPHPSerializedResponseWriter, TestLFUCache, TestSimpleTrackingShardHandler, AssignTest, CdcrBootstrapTest, CollectionsAPIAsyncDistributedZkTest, DistribCursorPagingTest, DistribJoinFromCollectionTest, DistributedVersionInfoTest, LeaderFailureAfterFreshStartTest, LeaderInitiatedRecoveryOnCommitTest, OverseerRolesTest, OverseerStatusTest, OverseerTaskQueueTest, RecoveryAfterSoftCommitTest, ReplicationFactorTest, SSLMigrationTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, SharedFSAutoReplicaFailoverUtilsTest, TestCloudPivotFacet, TestCloudRecovery, TestConfigSetsAPIZkFailure, TestDownShardTolerantSearch, TestLeaderElectionZkExpiry, TestLeaderInitiatedRecoveryThread, TestOnReconnectListenerSupport, TestRebalanceLeaders, TestSegmentSorting, TestSolrCloudWithKerberosAlt, TestStressLiveNodes, VMParamsZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZkTest, HdfsCollectionsAPIDistributedZkTest, HdfsNNFailoverTest, HdfsRecoveryZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HdfsRecoveryZkTest -Dtests.seed=AB2AB2C2DA355053 -Dtests.slow=true -Dtests.locale=es-CO -Dtests.timezone=Africa/Windhoek -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J1 | 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:704)
[junit4] > at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766)
[junit4] > at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774)
[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([AB2AB2C2DA355053]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:266)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [540/662 (1!)] on J1 in 64.79s, 1 test, 1 failure <<< FAILURES!
[...truncated 62805 lines...]
[JENKINS] Lucene-Solr-6.x-Solaris (64bit/jdk1.8.0) - Build # 561 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Solaris/561/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
expected:<3> but was:<1>
Stack Trace:
java.lang.AssertionError: expected:<3> but was:<1>
at __randomizedtesting.SeedInfo.seed([FC0068A0A00BD094:B4751C14A638FF01]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:516)
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.GeneratedConstructorAccessor146.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:704) at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766) at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774) 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.GeneratedConstructorAccessor146.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:704)
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766)
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774)
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([FC0068A0A00BD094]: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:266)
at sun.reflect.GeneratedMethodAccessor25.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 11479 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/init-core-data-001
[junit4] 2> 944393 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 944393 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001
[junit4] 2> 944394 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 944394 INFO (Thread-3199) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 944394 INFO (Thread-3199) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 944494 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44060
[junit4] 2> 944503 INFO (jetty-launcher-1590-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 944504 INFO (jetty-launcher-1590-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 944504 INFO (jetty-launcher-1590-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 944504 INFO (jetty-launcher-1590-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 944524 INFO (jetty-launcher-1590-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1ff15dad{/solr,null,AVAILABLE}
[junit4] 2> 944526 INFO (jetty-launcher-1590-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6588b5ad{/solr,null,AVAILABLE}
[junit4] 2> 944526 INFO (jetty-launcher-1590-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ad72140{/solr,null,AVAILABLE}
[junit4] 2> 944527 INFO (jetty-launcher-1590-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5b5bcbf3{/solr,null,AVAILABLE}
[junit4] 2> 944527 INFO (jetty-launcher-1590-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79b99274{HTTP/1.1,[http/1.1]}{127.0.0.1:54744}
[junit4] 2> 944527 INFO (jetty-launcher-1590-thread-4) [ ] o.e.j.s.Server Started @948708ms
[junit4] 2> 944528 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54744}
[junit4] 2> 944528 ERROR (jetty-launcher-1590-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@10926bbc{HTTP/1.1,[http/1.1]}{127.0.0.1:51783}
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-3) [ ] o.e.j.s.Server Started @948710ms
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51783}
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-20T00:35:43.668Z
[junit4] 2> 944529 ERROR (jetty-launcher-1590-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7b95d0a8{HTTP/1.1,[http/1.1]}{127.0.0.1:48967}
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-1) [ ] o.e.j.s.Server Started @948710ms
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48967}
[junit4] 2> 944529 ERROR (jetty-launcher-1590-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 944529 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-20T00:35:43.669Z
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-20T00:35:43.669Z
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5d916031{HTTP/1.1,[http/1.1]}{127.0.0.1:59668}
[junit4] 2> 944530 INFO (jetty-launcher-1590-thread-2) [ ] o.e.j.s.Server Started @948711ms
[junit4] 2> 944531 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59668}
[junit4] 2> 944531 ERROR (jetty-launcher-1590-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 944531 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0
[junit4] 2> 944531 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 944531 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 944531 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-20T00:35:43.670Z
[junit4] 2> 944535 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 944536 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 944540 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 944542 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 944542 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 944543 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 944543 INFO (jetty-launcher-1590-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44060/solr
[junit4] 2> 944549 INFO (jetty-launcher-1590-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44060/solr
[junit4] 2> 944555 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 944556 INFO (jetty-launcher-1590-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44060/solr
[junit4] 2> 944557 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15919a7c92e0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 944557 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15919a7c92e0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 944561 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 944562 INFO (jetty-launcher-1590-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44060/solr
[junit4] 2> 944595 INFO (jetty-launcher-1590-thread-4) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54744_solr
[junit4] 2> 944597 INFO (jetty-launcher-1590-thread-4) [n:127.0.0.1:54744_solr ] o.a.s.c.Overseer Overseer (id=97137075390644232-127.0.0.1:54744_solr-n_0000000000) starting
[junit4] 2> 944606 INFO (jetty-launcher-1590-thread-4) [n:127.0.0.1:54744_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54744_solr
[junit4] 2> 944632 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15919a7c92e0009, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 944644 INFO (jetty-launcher-1590-thread-2) [n:127.0.0.1:59668_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 944655 INFO (jetty-launcher-1590-thread-2) [n:127.0.0.1:59668_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59668_solr
[junit4] 2> 944662 INFO (zkCallback-1609-thread-1-processing-n:127.0.0.1:59668_solr) [n:127.0.0.1:59668_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 944675 INFO (jetty-launcher-1590-thread-1) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 944676 INFO (jetty-launcher-1590-thread-3) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 944682 INFO (jetty-launcher-1590-thread-1) [n:127.0.0.1:48967_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48967_solr
[junit4] 2> 944682 INFO (jetty-launcher-1590-thread-3) [n:127.0.0.1:51783_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51783_solr
[junit4] 2> 944692 INFO (zkCallback-1608-thread-1-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 944708 INFO (zkCallback-1609-thread-1-processing-n:127.0.0.1:59668_solr) [n:127.0.0.1:59668_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 944722 INFO (OverseerStateUpdate-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 944738 INFO (zkCallback-1613-thread-1-processing-n:127.0.0.1:48967_solr) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 944739 INFO (zkCallback-1612-thread-1-processing-n:127.0.0.1:51783_solr) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 944743 INFO (jetty-launcher-1590-thread-1) [n:127.0.0.1:48967_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/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/.
[junit4] 2> 944775 INFO (jetty-launcher-1590-thread-2) [n:127.0.0.1:59668_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/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node2/.
[junit4] 2> 944779 INFO (jetty-launcher-1590-thread-4) [n:127.0.0.1:54744_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/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node3/.
[junit4] 2> 944941 INFO (jetty-launcher-1590-thread-3) [n:127.0.0.1:51783_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/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node4/.
[junit4] 2> 944949 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 944951 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44060/solr ready
[junit4] 2> 945000 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 945002 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 945009 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 945014 INFO (OverseerThreadFactory-5021-thread-1-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.CreateCollectionCmd Create collection collection
[junit4] 2> 945015 WARN (OverseerThreadFactory-5021-thread-1-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 10 on collection collection is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 945015 ERROR (OverseerThreadFactory-5021-thread-1-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2 and value of replicationFactor is 10. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
[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> 945019 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=10
[junit4] 2> 945020 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 945055 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNoCollectionSpecified
[junit4] 2> 945057 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 945065 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002&collection.configName=conf&name=corewithnocollection&action=CREATE&numShards=1&collection=&wt=javabin&version=2
[junit4] 2> 945068 INFO (OverseerStateUpdate-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 946081 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 946099 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.IndexSchema [corewithnocollection] Schema name=minimal
[junit4] 2> 946099 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 946105 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.CoreContainer Creating SolrCore 'corewithnocollection' using configuration from collection corewithnocollection
[junit4] 2> 946106 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrCore [[corewithnocollection] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/corewithnocollection], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002/]
[junit4] 2> 946115 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 946115 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 946116 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 946116 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 946117 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.SolrIndexSearcher Opening [Searcher@259f0294[corewithnocollection] main]
[junit4] 2> 946119 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 946119 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 946119 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 946120 INFO (searcherExecutor-5030-thread-1-processing-n:127.0.0.1:48967_solr x:corewithnocollection c:corewithnocollection) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrCore [corewithnocollection] Registered new searcher Searcher@259f0294[corewithnocollection] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 946120 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554193208059101184
[junit4] 2> 946130 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 946130 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 946130 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48967/solr/corewithnocollection/
[junit4] 2> 946130 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 946130 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy http://127.0.0.1:48967/solr/corewithnocollection/ has no replicas
[junit4] 2> 946138 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48967/solr/corewithnocollection/ shard1
[junit4] 2> 946297 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 946300 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002&collection.configName=conf&name=corewithnocollection&action=CREATE&numShards=1&collection=&wt=javabin&version=2} status=0 QTime=1236
[junit4] 2> 946302 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002&collection.configName=conf&name=corewithnocollection2&action=CREATE&numShards=1&wt=javabin&version=2
[junit4] 2> 946305 INFO (OverseerStateUpdate-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 947020 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_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> 947323 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 947332 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.IndexSchema [corewithnocollection2] Schema name=minimal
[junit4] 2> 947335 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 947336 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.CoreContainer Creating SolrCore 'corewithnocollection2' using configuration from collection corewithnocollection2
[junit4] 2> 947336 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrCore [[corewithnocollection2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/corewithnocollection2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002/]
[junit4] 2> 947346 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 947346 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 947346 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 947346 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 947347 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.SolrIndexSearcher Opening [Searcher@8e92225[corewithnocollection2] main]
[junit4] 2> 947349 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 947349 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 947349 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 947349 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554193209347801088
[junit4] 2> 947349 INFO (searcherExecutor-5035-thread-1-processing-n:127.0.0.1:48967_solr x:corewithnocollection2 c:corewithnocollection2) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrCore [corewithnocollection2] Registered new searcher Searcher@8e92225[corewithnocollection2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 947359 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 947359 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 947359 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48967/solr/corewithnocollection2/
[junit4] 2> 947359 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 947359 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy http://127.0.0.1:48967/solr/corewithnocollection2/ has no replicas
[junit4] 2> 947367 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48967/solr/corewithnocollection2/ shard1
[junit4] 2> 947519 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 947523 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-002&collection.configName=conf&name=corewithnocollection2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1220
[junit4] 2> 947524 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNoCollectionSpecified
[junit4] 2> 947563 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionOnlyInZk
[junit4] 2> 947565 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 947569 INFO (qtp1374301387-10288) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 947573 INFO (OverseerThreadFactory-5021-thread-2-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 947576 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr ] o.a.s.c.SolrCore [corewithnocollection] CLOSING SolrCore org.apache.solr.core.SolrCore@3501eee4
[junit4] 2> 947579 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=corewithnocollection&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 948287 INFO (qtp1374301387-10288) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection&action=DELETE&wt=javabin&version=2} status=0 QTime=718
[junit4] 2> 948289 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 948294 INFO (OverseerThreadFactory-5021-thread-3-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 948294 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 948296 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.c.SolrCore [corewithnocollection2] CLOSING SolrCore org.apache.solr.core.SolrCore@7f143aec
[junit4] 2> 948300 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=corewithnocollection2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 949014 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection2&action=DELETE&wt=javabin&version=2} status=0 QTime=725
[junit4] 2> 949022 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 949026 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 949034 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 949041 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 949041 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 949043 INFO (qtp1374301387-10289) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 949048 INFO (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.CreateCollectionCmd Create collection onlyinzk
[junit4] 2> 949048 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 949256 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2
[junit4] 2> 949257 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2
[junit4] 2> 949367 INFO (zkCallback-1613-thread-1-processing-n:127.0.0.1:48967_solr) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 949367 INFO (zkCallback-1612-thread-1-processing-n:127.0.0.1:51783_solr) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 950272 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 950298 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.IndexSchema [onlyinzk_shard2_replica1] Schema name=minimal
[junit4] 2> 950300 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 950302 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard2_replica1' using configuration from collection onlyinzk
[junit4] 2> 950302 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [[onlyinzk_shard2_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node4/onlyinzk_shard2_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node4/./onlyinzk_shard2_replica1/data/]
[junit4] 2> 950305 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 950313 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.IndexSchema [onlyinzk_shard1_replica1] Schema name=minimal
[junit4] 2> 950314 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 950314 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 950315 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 950315 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 950315 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 950317 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6a7ea0d0[onlyinzk_shard2_replica1] main]
[junit4] 2> 950317 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard1_replica1' using configuration from collection onlyinzk
[junit4] 2> 950318 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [[onlyinzk_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/onlyinzk_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/./onlyinzk_shard1_replica1/data/]
[junit4] 2> 950318 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 950319 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 950319 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 950319 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554193212462071808
[junit4] 2> 950325 INFO (searcherExecutor-5040-thread-1-processing-n:127.0.0.1:51783_solr x:onlyinzk_shard2_replica1 s:shard2 c:onlyinzk) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] Registered new searcher Searcher@6a7ea0d0[onlyinzk_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 950326 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 950326 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 950327 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 950327 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 950327 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 950327 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 950327 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:51783/solr/onlyinzk_shard2_replica1/
[junit4] 2> 950327 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@31e5b5b5[onlyinzk_shard1_replica1] main]
[junit4] 2> 950327 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 950327 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:51783/solr/onlyinzk_shard2_replica1/ has no replicas
[junit4] 2> 950329 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 950329 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 950329 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 950329 INFO (searcherExecutor-5045-thread-1-processing-n:127.0.0.1:48967_solr x:onlyinzk_shard1_replica1 s:shard1 c:onlyinzk) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] Registered new searcher Searcher@31e5b5b5[onlyinzk_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 950329 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554193212472557568
[junit4] 2> 950333 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:51783/solr/onlyinzk_shard2_replica1/ shard2
[junit4] 2> 950337 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 950337 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 950337 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48967/solr/onlyinzk_shard1_replica1/
[junit4] 2> 950337 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 950337 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:48967/solr/onlyinzk_shard1_replica1/ has no replicas
[junit4] 2> 950342 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48967/solr/onlyinzk_shard1_replica1/ shard1
[junit4] 2> 950450 INFO (zkCallback-1613-thread-1-processing-n:127.0.0.1:48967_solr) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 950451 INFO (zkCallback-1612-thread-1-processing-n:127.0.0.1:51783_solr) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 950485 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 950488 INFO (qtp916004545-10270) [n:127.0.0.1:51783_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2} status=0 QTime=1232
[junit4] 2> 950493 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 950497 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2} status=0 QTime=1240
[junit4] 2> 950501 INFO (qtp1374301387-10289) [n:127.0.0.1:48967_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> 950603 INFO (zkCallback-1613-thread-1-processing-n:127.0.0.1:48967_solr) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 950603 INFO (zkCallback-1612-thread-1-processing-n:127.0.0.1:51783_solr) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 951051 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 951502 INFO (qtp1374301387-10289) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2460
[junit4] 2> 951505 INFO (qtp1374301387-10288) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 951505 INFO (qtp1374301387-10288) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 951505 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionOnlyInZk
[junit4] 2> 951549 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNoConfigSetExist
[junit4] 2> 951552 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 951556 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 951562 INFO (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 951567 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr ] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@da007f9
[junit4] 2> 951570 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr ] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@765e51b5
[junit4] 2> 951572 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 951579 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 952288 INFO (qtp1374301387-10278) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=733
[junit4] 2> 952291 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-003&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2
[junit4] 2> 952293 INFO (OverseerStateUpdate-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 953299 ERROR (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.c.c.ZkStateReader Specified config=[conf123] does not exist in ZooKeeper at location=[/configs/conf123]
[junit4] 2> 953300 ERROR (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.c.CoreContainer Error creating core [corewithnocollection3]: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> org.apache.solr.common.cloud.ZooKeeperException: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.readConfigName(ZkStateReader.java:189)
[junit4] 2> at org.apache.solr.cloud.CloudConfigSetService.createCoreResourceLoader(CloudConfigSetService.java:54)
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:74)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:779)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:377)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:365)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:156)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:152)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:664)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:445)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:318)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:269)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 953301 ERROR (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Error CREATEing SolrCore 'corewithnocollection3': Unable to create core [corewithnocollection3] Caused by: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:813)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:377)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:365)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:156)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:152)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:664)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:445)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:318)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:269)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Unable to create core [corewithnocollection3]
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:855)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:779)
[junit4] 2> ... 33 more
[junit4] 2> Caused by: org.apache.solr.common.cloud.ZooKeeperException: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.readConfigName(ZkStateReader.java:189)
[junit4] 2> at org.apache.solr.cloud.CloudConfigSetService.createCoreResourceLoader(CloudConfigSetService.java:54)
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:74)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840)
[junit4] 2> ... 34 more
[junit4] 2>
[junit4] 2> 953301 INFO (qtp1374301387-10280) [n:127.0.0.1:48967_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-003&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2} status=400 QTime=1010
[junit4] 2> 953505 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 953505 INFO (qtp1374301387-10287) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 953505 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNoConfigSetExist
[junit4] 2> 953556 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
[junit4] 2> 953558 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 953562 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection3&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 953565 INFO (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 953566 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 954275 INFO (qtp1374301387-10290) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection3&action=DELETE&wt=javabin&version=2} status=0 QTime=713
[junit4] 2> 954279 INFO (qtp1374301387-10289) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 954285 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 954286 INFO (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.CreateCollectionCmd Create collection oversharded
[junit4] 2> 954286 ERROR (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: oversharded operation: create failed:org.apache.solr.common.SolrException: Cannot create collection oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 3 and value of replicationFactor is 2. This requires 6 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
[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> 954291 INFO (qtp1374301387-10289) [n:127.0.0.1:48967_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2} status=400 QTime=11
[junit4] 2> 954291 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard
[junit4] 2> 954349 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[FC0068A0A00BD094]) [ ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
[junit4] 2> 954351 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[FC0068A0A00BD094]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 954355 INFO (qtp1374301387-10288) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 954358 INFO (OverseerThreadFactory-5021-thread-5-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.CreateCollectionCmd Create collection addReplicaColl
[junit4] 2> 954358 INFO (OverseerCollectionConfigSetProcessor-97137075390644232-127.0.0.1:54744_solr-n_0000000000) [n:127.0.0.1:54744_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000014 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 954573 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 954577 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 954578 INFO (qtp1538009533-10267) [n:127.0.0.1:59668_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 954579 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 954700 INFO (zkCallback-1613-thread-2-processing-n:127.0.0.1:48967_solr) [n:127.0.0.1:48967_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 954700 INFO (zkCallback-1608-thread-1-processing-n:127.0.0.1:54744_solr) [n:127.0.0.1:54744_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 954700 INFO (zkCallback-1609-thread-1-processing-n:127.0.0.1:59668_solr) [n:127.0.0.1:59668_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 954700 INFO (zkCallback-1612-thread-2-processing-n:127.0.0.1:51783_solr) [n:127.0.0.1:51783_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 955593 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 955594 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 955597 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 955614 INFO (qtp1538009533-10267) [n:127.0.0.1:59668_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
[junit4] 2> 955617 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
[junit4] 2> 955621 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 955622 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using configuration from collection addReplicaColl
[junit4] 2> 955622 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node4/addReplicaColl_shard1_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node4/./addReplicaColl_shard1_replica2/data/]
[junit4] 2> 955623 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
[junit4] 2> 955623 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
[junit4] 2> 955625 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 955625 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 955626 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using configuration from collection addReplicaColl
[junit4] 2> 955626 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/addReplicaColl_shard2_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node1/./addReplicaColl_shard2_replica2/data/]
[junit4] 2> 955627 INFO (qtp1538009533-10267) [n:127.0.0.1:59668_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
[junit4] 2> 955630 INFO (qtp1538009533-10267) [n:127.0.0.1:59668_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 955630 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using configuration from collection addReplicaColl
[junit4] 2> 955631 INFO (qtp27260732-10293) [n:127.0.0.1:54744_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node3/addReplicaColl_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-6.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_FC0068A0A00BD094-001/tempDir-001/node3/./addReplicaColl_shard1_replica1/data/]
[junit4] 2> 955634 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 955634 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 955636 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 955636 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 955636 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 955636 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 955636 INFO (qtp916004545-10272) [n:127.0.0.1:51783_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@2e7e63b5[addReplicaColl_shard1_replica2] main]
[junit4] 2> 955637 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 955637 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 955637 INFO (qtp1374301387-10268) [n:127.0.0.1:48967_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d90dd24[addReplicaColl_shard2_replica2] main]
[junit4] 2> 95
[...truncated too long message...]
rrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.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> 2451572 INFO (SUITE-HdfsRecoveryZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:48005 48005
[junit4] 2> 2451573 INFO (SUITE-HdfsRecoveryZkTest-seed#[FC0068A0A00BD094]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=sr-Latn, timezone=America/North_Dakota/Beulah
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_112 (64-bit)/cpus=3,threads=2,free=157600112,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TlogReplayBufferedWhileIndexingTest, PKIAuthenticationIntegrationTest, HdfsNNFailoverTest, TestFieldTypeResource, TestReqParamsAPI, TestCloudPivotFacet, BlobRepositoryCloudTest, BaseCdcrDistributedZkTest, TestExclusionRuleCollectionAccess, DocumentAnalysisRequestHandlerTest, AlternateDirectoryTest, TestGroupingSearch, BadComponentTest, TestCursorMarkWithoutUniqueKey, TestReplicationHandler, TestComplexPhraseQParserPlugin, ConcurrentDeleteAndCreateCollectionTest, TestBinaryResponseWriter, TestStressLucene, DistributedQueryElevationComponentTest, TestDocumentBuilder, TestPerFieldSimilarity, XsltUpdateRequestHandlerTest, HdfsWriteToMultipleCollectionsTest, AssignTest, TestComponentsName, AnalysisAfterCoreReloadTest, SpatialFilterTest, TestNamedUpdateProcessors, TestHighlightDedupGrouping, TestCollectionAPI, TestRandomCollapseQParserPlugin, TestElisionMultitermQuery, TestImplicitCoreProperties, DisMaxRequestHandlerTest, TestLRUCache, CollectionStateFormat2Test, TestLeaderInitiatedRecoveryThread, TestUniqueKeyFieldResource, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestLFUCache, OpenExchangeRatesOrgProviderTest, JavabinLoaderTest, TestLeaderElectionWithEmptyReplica, SecurityConfHandlerTest, TestPseudoReturnFields, TestLRUStatsCache, RecoveryAfterSoftCommitTest, BasicDistributedZkTest, FastVectorHighlighterTest, XmlUpdateRequestHandlerTest, TestBinaryResponseWriter, PeerSyncWithIndexFingerprintCachingTest, DocumentBuilderTest, TestBlobHandler, IndexBasedSpellCheckerTest, NumericFieldsTest, StatsReloadRaceTest, TestCollationField, TestSurroundQueryParser, DirectoryFactoryTest, TestLegacyFieldCache, TestManagedSchemaAPI, TestStressRecovery, TestClassicSimilarityFactory, TestManagedResource, CollectionsAPIAsyncDistributedZkTest, RuleEngineTest, TestLockTree, DistributedMLTComponentTest, SharedFSAutoReplicaFailoverUtilsTest, TestSizeLimitedDistributedMap, TestConfigSetImmutable, DistributedSpellCheckComponentTest, FacetPivotSmallTest, TestXIncludeConfig, TestFieldCacheReopen, CoreMergeIndexesAdminHandlerTest, SolrCLIZkUtilsTest, PolyFieldTest, UnloadDistributedZkTest, TestXmlQParserPlugin, HdfsSyncSliceTest, OverseerRolesTest, ClassificationUpdateProcessorIntegrationTest, TestBinaryField, ChaosMonkeyNothingIsSafeTest, HLLSerializationTest, TestCharFilters, TestNonDefinedSimilarityFactory, DeleteLastCustomShardedReplicaTest, TestSolrDeletionPolicy1, BlockDirectoryTest, LeaderFailoverAfterPartitionTest, MultiTermTest, SuggestComponentContextFilterQueryTest, TestGraphTermsQParserPlugin, JSONWriterTest, TestExactSharedStatsCache, TestFieldSortValues, DateFieldTest, MoreLikeThisHandlerTest, PeerSyncTest, TestSchemaManager, OverseerCollectionConfigSetProcessorTest, SimpleFacetsTest, TestSort, DistributedFacetPivotLargeTest, TestRTGBase, SchemaVersionSpecificBehaviorTest, TestFunctionQuery, TestSegmentSorting, TestHdfsBackupRestoreCore, TestPKIAuthenticationPlugin, TestChildDocTransformer, TestDefaultStatsCache, TestSolrConfigHandler, DocValuesMultiTest, ExplicitHLLTest, SyncSliceTest, WrapperMergePolicyFactoryTest, TestObjectReleaseTracker, BooleanFieldTest, ShufflingReplicaListTransformerTest, BJQParserTest, TestNumericTerms64, PathHierarchyTokenizerFactoryTest, SolrCoreTest, SolrTestCaseJ4Test, TestDefaultSearchFieldResource, CdcrRequestHandlerTest, TestPivotHelperCode, AtomicUpdatesTest, TestConfigSets, TestSha256AuthenticationProvider, DirectSolrSpellCheckerTest, TestCloudRecovery, TestGraphMLResponseWriter, TestBulkSchemaConcurrent, TestSQLHandler, ClusterStateUpdateTest, JSONWriterTest, TestFastOutputStream, PreAnalyzedUpdateProcessorTest, CurrencyFieldXmlFileTest, HdfsBasicDistributedZkTest, TestJsonFacets, TestRestManager, DeleteReplicaTest, RecoveryZkTest, TestStressReorder, UniqFieldsUpdateProcessorFactoryTest, TestSimpleQParserPlugin, DateRangeFieldTest, TestReloadAndDeleteDocs, DOMUtilTest, TestDocTermOrds, TermsComponentTest, ZkSolrClientTest, ZkCLITest, ShardRoutingCustomTest, TestFaceting, TestHashPartitioner, ZkControllerTest, TestJoin, TestReload, TestStressVersions, HardAutoCommitTest, TestRangeQuery, TestCoreContainer, TestSolr4Spatial, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, HighlighterTest, SoftAutoCommitTest, SolrIndexSplitterTest, SimplePostToolTest, TestCoreDiscovery, TestExtendedDismaxParser, SuggesterFSTTest, SolrRequestParserTest, DocValuesTest, TestTrie, SuggesterWFSTTest, TestCSVLoader, TestUpdate, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, DistanceFunctionTest, SolrInfoMBeanTest, LukeRequestHandlerTest, TestValueSourceCache, RequiredFieldsTest, IndexSchemaRuntimeFieldTest, IndexSchemaTest, UpdateRequestProcessorFactoryTest, QueryParsingTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, PingRequestHandlerTest, TestPostingsSolrHighlighter, TestPhraseSuggestions, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestJmxMonitoredMap, PluginInfoTest, DateMathParserTest, TestSuggestSpellingConverter, TestSolrJ, ZkNodePropsTest, UUIDFieldTest, DistributedIntervalFacetingTest, ActionThrottleTest, AsyncCallRequestStatusResponseTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionReloadTest, CollectionsAPISolrJTest, DeleteShardTest, DistribDocExpirationUpdateProcessorTest, LeaderElectionContextKeyTest, LeaderInitiatedRecoveryOnCommitTest, LeaderInitiatedRecoveryOnShardRestartTest, MigrateRouteKeyTest, MultiThreadedOCPTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerStatusTest, PeerSyncReplicationTest, SSLMigrationTest, ShardSplitTest, TestRequestForwarding, TestRequestStatusCollectionAPI, TestStressCloudBlindAtomicUpdates, TestTolerantUpdateProcessorCloud, TestTolerantUpdateProcessorRandomCloud, VMParamsZkACLAndCredentialsProvidersTest, HdfsChaosMonkeyNothingIsSafeTest, HdfsChaosMonkeySafeLeaderTest, HdfsCollectionsAPIDistributedZkTest, HdfsRecoveryZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HdfsRecoveryZkTest -Dtests.seed=FC0068A0A00BD094 -Dtests.slow=true -Dtests.locale=sr-Latn -Dtests.timezone=America/North_Dakota/Beulah -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[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:704)
[junit4] > at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:766)
[junit4] > at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1005)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:870)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:774)
[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([FC0068A0A00BD094]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:266)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [529/662 (2!)] on J0 in 58.15s, 1 test, 1 failure <<< FAILURES!
[...truncated 62873 lines...]