lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 238 - Still Unstable
Date Mon, 26 Dec 2016 15:19:01 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/238/

2 tests failed.
FAILED:  org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.testSpecificConfigsets

Error Message:
KeeperErrorCode = NoNode for /collections/withconfigset2

Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/withconfigset2
	at __randomizedtesting.SeedInfo.seed([D95ACC6B67E1C0E6:F424833190C57AEA]:0)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:356)
	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:353)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:353)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSpecificConfigsets(CollectionsAPIDistributedZkTest.java:425)
	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:  org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.testCollectionsAPI

Error Message:
Expected to see collection awhollynewcollection_0 null Last available state: DocCollection(awhollynewcollection_0//collections/awhollynewcollection_0/state.json/2)={   "replicationFactor":"1",   "shards":{"shard1":{       "range":"80000000-7fffffff",       "state":"active",       "replicas":{}}},   "router":{"name":"compositeId"},   "maxShardsPerNode":"1",   "autoAddReplicas":"false"}

Stack Trace:
java.lang.AssertionError: Expected to see collection awhollynewcollection_0
null
Last available state: DocCollection(awhollynewcollection_0//collections/awhollynewcollection_0/state.json/2)={
  "replicationFactor":"1",
  "shards":{"shard1":{
      "range":"80000000-7fffffff",
      "state":"active",
      "replicas":{}}},
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"1",
  "autoAddReplicas":"false"}
	at __randomizedtesting.SeedInfo.seed([D95ACC6B67E1C0E6:912FB8DF61D2EF73]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:265)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:496)
	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)




Build Log:
[...truncated 12500 lines...]
   [junit4] Suite: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/init-core-data-001
   [junit4]   2> 2442878 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 2442880 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001
   [junit4]   2> 2442882 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2442883 INFO  (Thread-180600) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2442883 INFO  (Thread-180600) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 2443053 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:46616
   [junit4]   2> 2443100 INFO  (jetty-launcher-1234-thread-1) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2443104 INFO  (jetty-launcher-1234-thread-2) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2443121 INFO  (jetty-launcher-1234-thread-3) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2443122 INFO  (jetty-launcher-1234-thread-4) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 2443179 INFO  (jetty-launcher-1234-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@791e61a6{/solr,null,AVAILABLE}
   [junit4]   2> 2443179 INFO  (jetty-launcher-1234-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@4f30a0d3{HTTP/1.1,[http/1.1]}{127.0.0.1:39680}
   [junit4]   2> 2443179 INFO  (jetty-launcher-1234-thread-1) [    ] o.e.j.s.Server Started @2448028ms
   [junit4]   2> 2443179 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39680}
   [junit4]   2> 2443180 ERROR (jetty-launcher-1234-thread-1) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2443180 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.4.0
   [junit4]   2> 2443180 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2443180 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2443180 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2016-12-26T14:14:00.458Z
   [junit4]   2> 2443275 INFO  (jetty-launcher-1234-thread-3) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@78f906d0{/solr,null,AVAILABLE}
   [junit4]   2> 2443335 INFO  (jetty-launcher-1234-thread-4) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@212ce97e{/solr,null,AVAILABLE}
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.e.j.s.AbstractConnector Started ServerConnector@2582d547{HTTP/1.1,[http/1.1]}{127.0.0.1:52017}
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.e.j.s.Server Started @2448184ms
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52017}
   [junit4]   2> 2443336 ERROR (jetty-launcher-1234-thread-4) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.4.0
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2443336 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2016-12-26T14:14:00.614Z
   [junit4]   2> 2443339 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.e.j.s.AbstractConnector Started ServerConnector@42e4bdb9{HTTP/1.1,[http/1.1]}{127.0.0.1:32943}
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.e.j.s.Server Started @2448192ms
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=32943}
   [junit4]   2> 2443343 ERROR (jetty-launcher-1234-thread-3) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.4.0
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2443343 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2443344 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2016-12-26T14:14:00.622Z
   [junit4]   2> 2443346 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2443371 INFO  (jetty-launcher-1234-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2c325c3f{/solr,null,AVAILABLE}
   [junit4]   2> 2443371 INFO  (jetty-launcher-1234-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@7f4a1ff2{HTTP/1.1,[http/1.1]}{127.0.0.1:41717}
   [junit4]   2> 2443371 INFO  (jetty-launcher-1234-thread-2) [    ] o.e.j.s.Server Started @2448220ms
   [junit4]   2> 2443371 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41717}
   [junit4]   2> 2443372 ERROR (jetty-launcher-1234-thread-2) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2443372 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 6.4.0
   [junit4]   2> 2443372 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2443372 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2443372 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2016-12-26T14:14:00.650Z
   [junit4]   2> 2443393 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2443394 INFO  (jetty-launcher-1234-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46616/solr
   [junit4]   2> 2443403 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2443413 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2443418 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2443427 INFO  (jetty-launcher-1234-thread-3) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46616/solr
   [junit4]   2> 2443438 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2443517 INFO  (jetty-launcher-1234-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46616/solr
   [junit4]   2> 2443545 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2443550 INFO  (jetty-launcher-1234-thread-4) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46616/solr
   [junit4]   2> 2443587 INFO  (jetty-launcher-1234-thread-1) [n:127.0.0.1:39680_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39680_solr
   [junit4]   2> 2443593 INFO  (jetty-launcher-1234-thread-1) [n:127.0.0.1:39680_solr    ] o.a.s.c.Overseer Overseer (id=97174266849722376-127.0.0.1:39680_solr-n_0000000000) starting
   [junit4]   2> 2443605 INFO  (jetty-launcher-1234-thread-2) [n:127.0.0.1:41717_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41717_solr
   [junit4]   2> 2443615 INFO  (zkCallback-1248-thread-1-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2443626 INFO  (jetty-launcher-1234-thread-3) [n:127.0.0.1:32943_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2443630 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2443640 INFO  (jetty-launcher-1234-thread-3) [n:127.0.0.1:32943_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32943_solr
   [junit4]   2> 2443642 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2443643 INFO  (zkCallback-1248-thread-1-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2443649 INFO  (jetty-launcher-1234-thread-1) [n:127.0.0.1:39680_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39680_solr
   [junit4]   2> 2443653 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2443658 INFO  (jetty-launcher-1234-thread-4) [n:127.0.0.1:52017_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 2443659 INFO  (zkCallback-1248-thread-1-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 2443684 INFO  (zkCallback-1253-thread-1-processing-n:127.0.0.1:32943_solr) [n:127.0.0.1:32943_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
   [junit4]   2> 2443693 INFO  (jetty-launcher-1234-thread-4) [n:127.0.0.1:52017_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52017_solr
   [junit4]   2> 2443695 INFO  (zkCallback-1253-thread-1-processing-n:127.0.0.1:32943_solr) [n:127.0.0.1:32943_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2443695 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2443695 INFO  (zkCallback-1248-thread-2-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2443707 INFO  (zkCallback-1258-thread-1-processing-n:127.0.0.1:52017_solr) [n:127.0.0.1:52017_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 2443780 INFO  (jetty-launcher-1234-thread-3) [n:127.0.0.1:32943_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node3/.
   [junit4]   2> 2443780 INFO  (jetty-launcher-1234-thread-2) [n:127.0.0.1:41717_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node2/.
   [junit4]   2> 2443781 INFO  (jetty-launcher-1234-thread-1) [n:127.0.0.1:39680_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node1/.
   [junit4]   2> 2443873 INFO  (jetty-launcher-1234-thread-4) [n:127.0.0.1:52017_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node4/.
   [junit4]   2> 2444088 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2444089 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46616/solr ready
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 2444176 WARN  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 2444221 WARN  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 2444228 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 2444274 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_37439_hdfs____luqhcw/webapp
   [junit4]   2> 2445033 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:37439
   [junit4]   2> 2445339 WARN  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 2445340 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 2445353 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_50317_datanode____.31h5vf/webapp
   [junit4]   2> 2445900 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:50317
   [junit4]   2> 2446041 WARN  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 2446043 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log jetty-6.1.26
   [junit4]   2> 2446070 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_54141_datanode____.bm72ui/webapp
   [junit4]   2> 2446213 INFO  (IPC Server handler 3 on 58090) [    ] BlockStateChange BLOCK* processReport: from storage DS-6ee5d4b1-6714-4b71-9419-38fd59369747 node DatanodeRegistration(127.0.0.1:39569, datanodeUuid=487a912e-241b-428c-a961-028d81a7929e, infoPort=45711, infoSecurePort=0, ipcPort=43467, storageInfo=lv=-56;cid=testClusterID;nsid=1906830613;c=0), blocks: 0, hasStaleStorage: true, processing time: 1 msecs
   [junit4]   2> 2446213 INFO  (IPC Server handler 3 on 58090) [    ] BlockStateChange BLOCK* processReport: from storage DS-c2b99d62-ba25-41de-957a-0b0e343d343a node DatanodeRegistration(127.0.0.1:39569, datanodeUuid=487a912e-241b-428c-a961-028d81a7929e, infoPort=45711, infoSecurePort=0, ipcPort=43467, storageInfo=lv=-56;cid=testClusterID;nsid=1906830613;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 2446702 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:54141
   [junit4]   2> 2446909 INFO  (IPC Server handler 5 on 58090) [    ] BlockStateChange BLOCK* processReport: from storage DS-b659f7be-0db9-42bf-983d-7c5709ba47c2 node DatanodeRegistration(127.0.0.1:39240, datanodeUuid=277fe70b-700e-48f8-837c-bdcb6221211c, infoPort=39957, infoSecurePort=0, ipcPort=44826, storageInfo=lv=-56;cid=testClusterID;nsid=1906830613;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 2446910 INFO  (IPC Server handler 5 on 58090) [    ] BlockStateChange BLOCK* processReport: from storage DS-30d062d2-1d13-438e-a9af-6b5791def117 node DatanodeRegistration(127.0.0.1:39240, datanodeUuid=277fe70b-700e-48f8-837c-bdcb6221211c, infoPort=39957, infoSecurePort=0, ipcPort=44826, storageInfo=lv=-56;cid=testClusterID;nsid=1906830613;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 2447171 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionOnlyInZk
   [junit4]   2> 2447173 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2447182 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_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> 2447195 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=12
   [junit4]   2> 2447197 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2447197 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_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> 2447199 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_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> 2447205 INFO  (OverseerThreadFactory-4330-thread-2-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.CreateCollectionCmd Create collection onlyinzk
   [junit4]   2> 2447205 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2447316 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2447330 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2447445 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_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> 2447445 INFO  (zkCallback-1253-thread-1-processing-n:127.0.0.1:32943_solr) [n:127.0.0.1:32943_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> 2448342 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
   [junit4]   2> 2448344 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
   [junit4]   2> 2448350 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.s.IndexSchema [onlyinzk_shard2_replica1] Schema name=minimal
   [junit4]   2> 2448371 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2448376 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2448380 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.s.IndexSchema [onlyinzk_shard1_replica1] Schema name=minimal
   [junit4]   2> 2448384 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:58090/data
   [junit4]   2> 2448384 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 2448384 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [[onlyinzk_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node2/onlyinzk_shard2_replica1], dataDir=[hdfs://localhost:58090/data/onlyinzk/core_node2/data/]
   [junit4]   2> 2448384 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node2/data/snapshot_metadata
   [junit4]   2> 2448385 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2448390 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2448391 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:58090/data
   [junit4]   2> 2448391 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 2448391 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [[onlyinzk_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node3/onlyinzk_shard1_replica1], dataDir=[hdfs://localhost:58090/data/onlyinzk/core_node1/data/]
   [junit4]   2> 2448391 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node1/data/snapshot_metadata
   [junit4]   2> 2448393 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2448393 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_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> 2448393 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Creating new global HDFS BlockCache
   [junit4]   2> 2448399 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2448400 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_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> 2448427 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2448428 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2448428 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node1/data
   [junit4]   2> 2448431 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node2/data
   [junit4]   2> 2448463 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node2/data/index
   [junit4]   2> 2448467 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/onlyinzk/core_node1/data/index
   [junit4]   2> 2448473 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2448473 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_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> 2448475 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2448475 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_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> 2448484 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2448489 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2448550 INFO  (IPC Server handler 6 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39240 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-c2b99d62-ba25-41de-957a-0b0e343d343a:NORMAL:127.0.0.1:39569|RBW], ReplicaUC[[DISK]DS-b659f7be-0db9-42bf-983d-7c5709ba47c2:NORMAL:127.0.0.1:39240|RBW]]} size 0
   [junit4]   2> 2448550 INFO  (IPC Server handler 7 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39569 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-b659f7be-0db9-42bf-983d-7c5709ba47c2:NORMAL:127.0.0.1:39240|RBW], ReplicaUC[[DISK]DS-6ee5d4b1-6714-4b71-9419-38fd59369747:NORMAL:127.0.0.1:39569|FINALIZED]]} size 0
   [junit4]   2> 2448555 INFO  (IPC Server handler 4 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39569 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-30d062d2-1d13-438e-a9af-6b5791def117:NORMAL:127.0.0.1:39240|RBW], ReplicaUC[[DISK]DS-c2b99d62-ba25-41de-957a-0b0e343d343a:NORMAL:127.0.0.1:39569|RBW]]} size 0
   [junit4]   2> 2448555 INFO  (IPC Server handler 5 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39240 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-30d062d2-1d13-438e-a9af-6b5791def117:NORMAL:127.0.0.1:39240|RBW], ReplicaUC[[DISK]DS-c2b99d62-ba25-41de-957a-0b0e343d343a:NORMAL:127.0.0.1:39569|RBW]]} size 0
   [junit4]   2> 2448580 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 2448580 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2448580 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 2448581 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 2448581 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2448581 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 2448596 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2448596 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2448596 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2448596 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2448614 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@707ef40c[onlyinzk_shard1_replica1] main]
   [junit4]   2> 2448616 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 2448616 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2448616 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2448616 INFO  (searcherExecutor-4340-thread-1-processing-n:127.0.0.1:32943_solr x:onlyinzk_shard1_replica1 s:shard1 c:onlyinzk) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] Registered new searcher Searcher@707ef40c[onlyinzk_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2448617 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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 1554788275605995520
   [junit4]   2> 2448617 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@25acc9[onlyinzk_shard2_replica1] main]
   [junit4]   2> 2448620 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 2448620 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2448620 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2448620 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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 1554788275609141248
   [junit4]   2> 2448622 INFO  (searcherExecutor-4339-thread-1-processing-n:127.0.0.1:41717_solr x:onlyinzk_shard2_replica1 s:shard2 c:onlyinzk) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] Registered new searcher Searcher@25acc9[onlyinzk_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2448628 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2448628 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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> 2448628 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41717/solr/onlyinzk_shard2_replica1/
   [junit4]   2> 2448628 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 2448628 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:41717/solr/onlyinzk_shard2_replica1/ has no replicas
   [junit4]   2> 2448635 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2448635 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2448635 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:32943/solr/onlyinzk_shard1_replica1/
   [junit4]   2> 2448635 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 2448635 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:32943/solr/onlyinzk_shard1_replica1/ has no replicas
   [junit4]   2> 2448642 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41717/solr/onlyinzk_shard2_replica1/ shard2
   [junit4]   2> 2448647 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:32943/solr/onlyinzk_shard1_replica1/ shard1
   [junit4]   2> 2448753 INFO  (zkCallback-1253-thread-1-processing-n:127.0.0.1:32943_solr) [n:127.0.0.1:32943_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> 2448753 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_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> 2448793 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_solr c:onlyinzk s:shard2  x:onlyinzk_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2448796 INFO  (qtp567562852-187402) [n:127.0.0.1:41717_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=1465
   [junit4]   2> 2448798 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_solr c:onlyinzk s:shard1  x:onlyinzk_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2448800 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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=1485
   [junit4]   2> 2448804 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_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> 2448905 INFO  (zkCallback-1253-thread-1-processing-n:127.0.0.1:32943_solr) [n:127.0.0.1:32943_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> 2448905 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_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> 2449208 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2449804 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_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=2604
   [junit4]   2> 2449806 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2449806 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_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> 2449807 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionOnlyInZk
   [junit4]   2> 2449948 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
   [junit4]   2> 2449949 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2449953 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_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> 2449971 INFO  (OverseerThreadFactory-4330-thread-3-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 2449977 INFO  (qtp373682764-187389) [n:127.0.0.1:32943_solr    ] o.a.s.c.SolrCore [onlyinzk_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7d3f8a14
   [junit4]   2> 2449977 INFO  (qtp567562852-187403) [n:127.0.0.1:41717_solr    ] o.a.s.c.SolrCore [onlyinzk_shard2_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@23426927
   [junit4]   2> 2449991 INFO  (qtp567562852-187403) [n:127.0.0.1:41717_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node2/data
   [junit4]   2> 2449992 INFO  (qtp567562852-187403) [n:127.0.0.1:41717_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node2/data/snapshot_metadata
   [junit4]   2> 2449992 INFO  (qtp373682764-187389) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node1/data/index
   [junit4]   2> 2449994 INFO  (qtp567562852-187403) [n:127.0.0.1:41717_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node2/data/index
   [junit4]   2> 2450000 INFO  (qtp373682764-187389) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node1/data/snapshot_metadata
   [junit4]   2> 2450000 INFO  (qtp373682764-187389) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/onlyinzk/core_node1/data
   [junit4]   2> 2450011 INFO  (IPC Server handler 7 on 58090) [    ] BlockStateChange BLOCK* addToInvalidates: blk_1073741825_1001 127.0.0.1:39569 127.0.0.1:39240 
   [junit4]   2> 2450016 INFO  (IPC Server handler 6 on 58090) [    ] BlockStateChange BLOCK* addToInvalidates: blk_1073741826_1002 127.0.0.1:39240 127.0.0.1:39569 
   [junit4]   2> 2450026 INFO  (qtp373682764-187389) [n:127.0.0.1:32943_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=50
   [junit4]   2> 2450029 INFO  (qtp567562852-187403) [n:127.0.0.1:41717_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=53
   [junit4]   2> 2450738 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=785
   [junit4]   2> 2450743 INFO  (qtp373682764-187394) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2450748 INFO  (OverseerThreadFactory-4330-thread-4-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.CreateCollectionCmd Create collection acollection
   [junit4]   2> 2450754 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2450754 ERROR (OverseerThreadFactory-4330-thread-4-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:112)
   [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> 2450768 INFO  (qtp373682764-187394) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=24
   [junit4]   2> 2450771 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
   [junit4]   2> 2450956 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
   [junit4]   2> 2450958 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2450961 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2450965 INFO  (OverseerThreadFactory-4330-thread-5-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.CreateCollectionCmd Create collection collection
   [junit4]   2> 2450965 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2450968 WARN  (OverseerThreadFactory-4330-thread-5-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_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> 2450969 ERROR (OverseerThreadFactory-4330-thread-5-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_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> 2450972 INFO  (qtp373682764-187390) [n:127.0.0.1:32943_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> 2450972 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
   [junit4]   2> 2451132 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionRemovesStaleZkCollectionsNode
   [junit4]   2> 2451133 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2451143 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=out_of_sync_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2451155 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2451161 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=out_of_sync_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=18
   [junit4]   2> 2451164 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2451164 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_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> 2451164 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionRemovesStaleZkCollectionsNode
   [junit4]   2> 2451196 INFO  (org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor@37063ca6) [    ] BlockStateChange BLOCK* BlockManager: ask 127.0.0.1:39240 to delete [blk_1073741825_1001, blk_1073741826_1002]
   [junit4]   2> 2451311 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
   [junit4]   2> 2451312 INFO  (TEST-HdfsCollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[D95ACC6B67E1C0E6]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 2451316 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
   [junit4]   2> 2451318 INFO  (OverseerStateUpdate-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_solr    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
   [junit4]   2> 2452332 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
   [junit4]   2> 2452339 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
   [junit4]   2> 2452345 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2452350 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
   [junit4]   2> 2452350 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:58090/data
   [junit4]   2> 2452350 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 2452350 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node3/halfdeletedcollection_shard1_replica1], dataDir=[hdfs://localhost:58090/data/halfdeletedcollection/core_node1//x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003/]
   [junit4]   2> 2452351 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1//x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003/snapshot_metadata
   [junit4]   2> 2452371 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2452371 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_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> 2452379 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2452383 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1//x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003
   [junit4]   2> 2452411 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1//x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003/index
   [junit4]   2> 2452434 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2452434 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_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> 2452437 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2452488 INFO  (IPC Server handler 1 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39569 is added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-30d062d2-1d13-438e-a9af-6b5791def117:NORMAL:127.0.0.1:39240|RBW], ReplicaUC[[DISK]DS-6ee5d4b1-6714-4b71-9419-38fd59369747:NORMAL:127.0.0.1:39569|FINALIZED]]} size 0
   [junit4]   2> 2452489 INFO  (IPC Server handler 0 on 58090) [    ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:39240 is added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-6ee5d4b1-6714-4b71-9419-38fd59369747:NORMAL:127.0.0.1:39569|FINALIZED], ReplicaUC[[DISK]DS-b659f7be-0db9-42bf-983d-7c5709ba47c2:NORMAL:127.0.0.1:39240|FINALIZED]]} size 0
   [junit4]   2> 2452505 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 2452505 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2452505 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 2452517 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2452517 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2452533 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5b1b4c0f[halfdeletedcollection_shard1_replica1] main]
   [junit4]   2> 2452535 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 2452536 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 2452536 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2452536 INFO  (searcherExecutor-4349-thread-1-processing-n:127.0.0.1:32943_solr x:halfdeletedcollection_shard1_replica1 c:halfdeletedcollection) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@5b1b4c0f[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2452536 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554788279715364864
   [junit4]   2> 2452546 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2452546 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2452546 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:32943/solr/halfdeletedcollection_shard1_replica1/
   [junit4]   2> 2452546 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 2452546 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:32943/solr/halfdeletedcollection_shard1_replica1/ has no replicas
   [junit4]   2> 2452550 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:32943/solr/halfdeletedcollection_shard1_replica1/ shard2
   [junit4]   2> 2452701 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2452704 INFO  (qtp373682764-187392) [n:127.0.0.1:32943_solr c:halfdeletedcollection   x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=1388
   [junit4]   2> 2452706 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2452716 INFO  (OverseerThreadFactory-4330-thread-5-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 2452716 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2452719 INFO  (qtp373682764-187396) [n:127.0.0.1:32943_solr    ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ef6f014
   [junit4]   2> 2452732 INFO  (qtp373682764-187396) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/halfdeletedcollection/core_node1/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003/index
   [junit4]   2> 2452733 INFO  (qtp373682764-187396) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/halfdeletedcollection/core_node1/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003
   [junit4]   2> 2452735 INFO  (qtp373682764-187396) [n:127.0.0.1:32943_solr    ] o.a.s.s.h.HdfsDirectory Closing hdfs directory hdfs://localhost:58090/data/halfdeletedcollection/core_node1/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-003/snapshot_metadata
   [junit4]   2> 2452747 INFO  (IPC Server handler 6 on 58090) [    ] BlockStateChange BLOCK* addToInvalidates: blk_1073741827_1003 127.0.0.1:39240 127.0.0.1:39569 
   [junit4]   2> 2452754 INFO  (qtp373682764-187396) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=36
   [junit4]   2> 2453458 INFO  (qtp373682764-187395) [n:127.0.0.1:32943_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=751
   [junit4]   2> 2453460 INFO  (qtp373682764-187394) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2453460 INFO  (qtp373682764-187394) [n:127.0.0.1:32943_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> 2453462 INFO  (qtp373682764-187393) [n:127.0.0.1:32943_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2453466 INFO  (OverseerThreadFactory-4330-thread-5-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
   [junit4]   2> 2453467 INFO  (OverseerCollectionConfigSetProcessor-97174266849722376-127.0.0.1:39680_solr-n_0000000000) [n:127.0.0.1:39680_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> 2453675 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2
   [junit4]   2> 2453676 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2
   [junit4]   2> 2453786 INFO  (zkCallback-1254-thread-1-processing-n:127.0.0.1:41717_solr) [n:127.0.0.1:41717_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 2453786 INFO  (zkCallback-1248-thread-1-processing-n:127.0.0.1:39680_solr) [n:127.0.0.1:39680_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 2454197 INFO  (org.apache.hadoop.hdfs.server.blockmanagement.BlockManager$ReplicationMonitor@37063ca6) [    ] BlockStateChange BLOCK* BlockManager: ask 127.0.0.1:39240 to delete [blk_1073741827_1003]
   [junit4]   2> 2454695 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
   [junit4]   2> 2454700 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0
   [junit4]   2> 2454730 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
   [junit4]   2> 2454733 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2454734 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
   [junit4]   2> 2454736 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:58090/data
   [junit4]   2> 2454736 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 2454736 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node1/halfdeletedcollection_shard1_replica1], dataDir=[hdfs://localhost:58090/data/halfdeletedcollection/core_node2/data/]
   [junit4]   2> 2454736 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node2/data/snapshot_metadata
   [junit4]   2> 2454739 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
   [junit4]   2> 2454741 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2454742 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection
   [junit4]   2> 2454742 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:58090/data
   [junit4]   2> 2454742 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 2454743 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001/tempDir-001/node2/halfdeletedcollection_shard2_replica1], dataDir=[hdfs://localhost:58090/data/halfdeletedcollection/core_node1/data/]
   [junit4]   2> 2454743 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1/data/snapshot_metadata
   [junit4]   2> 2454748 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2454748 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_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> 2454749 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2454749 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_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> 2454751 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2454752 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node2/data
   [junit4]   2> 2454759 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2454759 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1/data
   [junit4]   2> 2454781 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node2/data/index
   [junit4]   2> 2454787 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
   [junit4]   2> 2454787 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_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> 2454789 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollection s:shard2  x:halfdeletedcollection_shard2_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:58090/data/halfdeletedcollection/core_node1/data/index
   [junit4]   2> 2454792 INFO  (qtp1411059238-187380) [n:127.0.0.1:39680_solr c:halfdeletedcollection s:shard1  x:halfdeletedcollection_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 2454798 INFO  (qtp567562852-187399) [n:127.0.0.1:41717_solr c:halfdeletedcollec

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

rver2$SelectChannelConnectorWithSafeStartup@localhost:0
   [junit4]   2> 2608571 ERROR (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.h.m.l.MethodMetric Error invoking method getBlocksTotal
   [junit4]   2> java.lang.reflect.InvocationTargetException
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:498)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:111)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:144)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:401)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:79)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:194)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:172)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:151)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1804)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
   [junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
   [junit4]   2> 	at org.apache.hadoop.metrics2.util.MBeans.unregister(MBeans.java:81)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:226)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:211)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:463)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:213)
   [junit4]   2> 	at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:594)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
   [junit4]   2> 	at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:171)
   [junit4]   2> 	at org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:872)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1726)
   [junit4]   2> 	at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1705)
   [junit4]   2> 	at org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:198)
   [junit4]   2> 	at org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.teardownClass(HdfsCollectionsAPIDistributedZkTest.java:52)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]   2> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	at java.lang.reflect.Method.invoke(Method.java:498)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2> 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.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> 2608574 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46616 46616
   [junit4]   2> 2608574 INFO  (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[D95ACC6B67E1C0E6]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_D95ACC6B67E1C0E6-001
   [junit4]   2> Dec 26, 2016 2:16:45 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 35 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): {}, docValues:{}, maxPointsInLeafNode=1088, maxMBSortInHeap=5.808594180330708, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=en, timezone=Europe/Vatican
   [junit4]   2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=4,threads=2,free=161122008,total=522190848
   [junit4]   2> NOTE: All tests run in this JVM: [DistributedFacetPivotWhiteBoxTest, TestExactSharedStatsCache, ScriptEngineTest, TestRandomFaceting, TestReplicationHandler, BooleanFieldTest, TestFastWriter, TestDocSet, TestPivotHelperCode, TestCryptoKeys, ReplaceNodeTest, TestBadConfig, SegmentsInfoRequestHandlerTest, ParsingFieldUpdateProcessorsTest, FastVectorHighlighterTest, TriLevelCompositeIdRoutingTest, TestRandomFlRTGCloud, TestConfigSetsAPI, CollectionTooManyReplicasTest, TestScoreJoinQPScore, HttpSolrCallGetCoreTest, TestLeaderElectionWithEmptyReplica, StandardRequestHandlerTest, TestDocBasedVersionConstraints, TestSolr4Spatial, TestSolrCoreProperties, BasicDistributedZkTest, ClusterStateTest, TestPKIAuthenticationPlugin, BasicZkTest, XsltUpdateRequestHandlerTest, TestCSVLoader, TestHighlightDedupGrouping, TestSolrConfigHandlerConcurrent, TestImplicitCoreProperties, TestSolrCloudSnapshots, TestMinMaxOnMultiValuedField, AlternateDirectoryTest, TestStressLucene, TestComponentsName, ShufflingReplicaListTransformerTest, TestDownShardTolerantSearch, ExternalFileFieldSortTest, TestAnalyzeInfixSuggestions, TestSolr4Spatial2, TestNonDefinedSimilarityFactory, ClassificationUpdateProcessorFactoryTest, ConcurrentDeleteAndCreateCollectionTest, DefaultValueUpdateProcessorTest, TestCloudManagedSchema, TestDocumentBuilder, SimpleCollectionCreateDeleteTest, TestAtomicUpdateErrorCases, TestManagedSchemaThreadSafety, SolrCoreTest, TestFreeTextSuggestions, OverriddenZkACLAndCredentialsProvidersTest, TestCorePropertiesReload, BlockDirectoryTest, DocumentAnalysisRequestHandlerTest, ReturnFieldsTest, HdfsLockFactoryTest, TestFieldCacheReopen, SmileWriterTest, TestExportWriter, DateFieldTest, FileBasedSpellCheckerTest, HdfsBasicDistributedZkTest, HttpPartitionTest, DistributedExpandComponentTest, TestDelegationWithHadoopAuth, OutputWriterTest, UUIDFieldTest, TestRangeQuery, AnalysisAfterCoreReloadTest, TestFaceting, HighlighterMaxOffsetTest, TestFunctionQuery, TestCrossCoreJoin, TestRealTimeGet, HdfsCollectionsAPIDistributedZkTest]
   [junit4] Completed [413/665 (1!)] on J0 in 175.60s, 20 tests, 1 failure, 1 error <<< FAILURES!

[...truncated 63253 lines...]



Mime
View raw message