Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1261/

1 tests failed.
FAILED:  
org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.testCollectionsAPI

Error Message:
expected:<3> but was:<0>

Stack Trace:
java.lang.AssertionError: expected:<3> but was:<0>
        at 
__randomizedtesting.SeedInfo.seed([8DD03C4F06B63688:C5A548FB0085191D]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.failNotEquals(Assert.java:647)
        at org.junit.Assert.assertEquals(Assert.java:128)
        at org.junit.Assert.assertEquals(Assert.java:472)
        at org.junit.Assert.assertEquals(Assert.java:456)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:523)
        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:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 13190 lines...]
   [junit4] Suite: 
org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/init-core-data-001
   [junit4]   2> 3362468 WARN  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=110 numCloses=110
   [junit4]   2> 3362469 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.SolrTestCaseJ4 Using TrieFields
   [junit4]   2> 3362476 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-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> 3362478 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001
   [junit4]   2> 3362478 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3362501 INFO  (Thread-67337) [    ] o.a.s.c.ZkTestServer 
client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3362501 INFO  (Thread-67337) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3362596 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.ZkTestServer start zk server on port:60357
   [junit4]   2> 3362629 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3362631 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3362633 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3362635 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3362636 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7c296459{/solr,null,AVAILABLE}
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@201bd23d{HTTP/1.1,[http/1.1]}{127.0.0.1:39325}
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.e.j.s.Server Started @3365455ms
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=39325}
   [junit4]   2> 3362638 ERROR (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3362638 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-03-13T06:39:53.177Z
   [junit4]   2> 3362644 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@47dbdb23{/solr,null,AVAILABLE}
   [junit4]   2> 3362644 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@28bd47a9{HTTP/1.1,[http/1.1]}{127.0.0.1:57381}
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.e.j.s.Server Started @3365462ms
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=57381}
   [junit4]   2> 3362645 ERROR (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3362645 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-03-13T06:39:53.184Z
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@51507b09{/solr,null,AVAILABLE}
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@3881817{HTTP/1.1,[http/1.1]}{127.0.0.1:33493}
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.e.j.s.Server Started @3365568ms
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=33493}
   [junit4]   2> 3362751 ERROR (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 3362751 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3362752 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3362752 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-03-13T06:39:53.291Z
   [junit4]   2> 3362758 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3362771 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@302ab97b{/solr,null,AVAILABLE}
   [junit4]   2> 3362771 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@3710b134{HTTP/1.1,[http/1.1]}{127.0.0.1:58329}
   [junit4]   2> 3362771 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.e.j.s.Server Started @3365589ms
   [junit4]   2> 3362771 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=58329}
   [junit4]   2> 3362772 ERROR (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3362772 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 3362772 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3362772 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3362772 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-03-13T06:39:53.311Z
   [junit4]   2> 3362778 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3362779 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3362785 INFO  (jetty-launcher-25998-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60357/solr
   [junit4]   2> 3362801 INFO  (jetty-launcher-25998-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60357/solr
   [junit4]   2> 3362801 INFO  (jetty-launcher-25998-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60357/solr
   [junit4]   2> 3362809 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3362810 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15ac66502db0005, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3362815 INFO  (jetty-launcher-25998-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60357/solr
   [junit4]   2> 3362816 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15ac66502db0007, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3362820 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15ac66502db0009, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3362830 INFO  (jetty-launcher-25998-thread-1) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3362830 INFO  (jetty-launcher-25998-thread-1) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:39325_solr
   [junit4]   2> 3362831 INFO  (jetty-launcher-25998-thread-1) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.Overseer Overseer 
(id=97608479083790344-127.0.0.1:39325_solr-n_0000000000) starting
   [junit4]   2> 3362842 INFO  (jetty-launcher-25998-thread-4) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3362843 INFO  (jetty-launcher-25998-thread-4) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:58329_solr
   [junit4]   2> 3362867 INFO  (jetty-launcher-25998-thread-2) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3362873 INFO  
(zkCallback-26014-thread-1-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3362874 INFO  (jetty-launcher-25998-thread-3) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3362874 INFO  (jetty-launcher-25998-thread-2) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3362875 INFO  (jetty-launcher-25998-thread-3) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:57381_solr
   [junit4]   2> 3362882 INFO  (jetty-launcher-25998-thread-1) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:39325_solr
   [junit4]   2> 3362894 INFO  
(zkCallback-26020-thread-2-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3362930 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (3)
   [junit4]   2> 3362930 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3362932 INFO  (jetty-launcher-25998-thread-2) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33493_solr
   [junit4]   2> 3362937 INFO  
(zkCallback-26014-thread-2-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (3)
   [junit4]   2> 3362937 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (3)
   [junit4]   2> 3362938 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3362938 INFO  
(zkCallback-26014-thread-2-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3362941 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3362941 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3363046 INFO  (jetty-launcher-25998-thread-1) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node1/.
   [junit4]   2> 3363107 INFO  (jetty-launcher-25998-thread-2) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node2/.
   [junit4]   2> 3363118 INFO  (jetty-launcher-25998-thread-4) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node4/.
   [junit4]   2> 3363165 INFO  (jetty-launcher-25998-thread-3) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node3/.
   [junit4]   2> 3364662 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3364663 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:60357/solr ready
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 3364703 WARN  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried 
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 3364720 WARN  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 3364721 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.m.log jetty-6.1.26
   [junit4]   2> 3364733 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-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_40276_hdfs____.3w33k1/webapp
   [junit4]   2> 3365113 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:40276
   [junit4]   2> 3365188 WARN  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 3365189 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.m.log jetty-6.1.26
   [junit4]   2> 3365198 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-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_55051_datanode____hoeihf/webapp
   [junit4]   2> 3365554 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.m.log Started 
HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:55051
   [junit4]   2> 3365664 INFO  (IPC Server handler 4 on 54991) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-396afd20-01b8-4429-b68c-004c3819191a node 
DatanodeRegistration(127.0.0.1:52646, 
datanodeUuid=b5ea20e9-661d-45ce-a8de-739cc22cf00d, infoPort=59353, 
infoSecurePort=0, ipcPort=36778, 
storageInfo=lv=-56;cid=testClusterID;nsid=600010899;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 3365664 INFO  (IPC Server handler 4 on 54991) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-6b23e885-f071-4d9d-8c64-d5b6714a73b2 node 
DatanodeRegistration(127.0.0.1:52646, 
datanodeUuid=b5ea20e9-661d-45ce-a8de-739cc22cf00d, infoPort=59353, 
infoSecurePort=0, ipcPort=36778, 
storageInfo=lv=-56;cid=testClusterID;nsid=600010899;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 1 msecs
   [junit4]   2> 3365767 INFO  
(TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[8DD03C4F06B63688])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
   [junit4]   2> 3365767 INFO  
(TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[8DD03C4F06B63688])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3365770 INFO  (qtp866721603-166070) [n:127.0.0.1:57381_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> 3365773 INFO  
(OverseerThreadFactory-11683-thread-1-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
acollection
   [junit4]   2> 3365774 ERROR 
(OverseerThreadFactory-11683-thread-1-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_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> 3365776 INFO  (qtp866721603-166070) [n:127.0.0.1:57381_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=6
   [junit4]   2> 3365776 INFO  
(TEST-HdfsCollectionsAPIDistributedZkTest.testMissingNumShards-seed#[8DD03C4F06B63688])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
   [junit4]   2> 3365846 INFO  
(TEST-HdfsCollectionsAPIDistributedZkTest.addReplicaTest-seed#[8DD03C4F06B63688])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
   [junit4]   2> 3365847 INFO  
(TEST-HdfsCollectionsAPIDistributedZkTest.addReplicaTest-seed#[8DD03C4F06B63688])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3365848 INFO  (qtp866721603-166071) [n:127.0.0.1:57381_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 3365857 INFO  
(OverseerCollectionConfigSetProcessor-97608479083790344-127.0.0.1:39325_solr-n_0000000000)
 [n:127.0.0.1:39325_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> 3365859 INFO  
(OverseerThreadFactory-11683-thread-2-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
addReplicaColl
   [junit4]   2> 3365969 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 3365970 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr   
 ] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 3365973 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 3365984 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 3366113 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3366113 INFO  
(zkCallback-26014-thread-2-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3366113 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3366113 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3366990 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 3366994 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 3366996 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
   [junit4]   2> 3366998 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 3366999 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3367000 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using 
configuration from collection addReplicaColl
   [junit4]   2> 3367012 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:54991/data
   [junit4]   2> 3367013 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3367013 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore 
[[addReplicaColl_shard1_replica2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node3/addReplicaColl_shard1_replica2],
 dataDir=[hdfs://localhost:54991/data/addReplicaColl/core_node2/data/]
   [junit4]   2> 3367013 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6aabcf45
   [junit4]   2> 3367013 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 3367013 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node2/data/snapshot_metadata
   [junit4]   2> 3367020 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3367020 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3367022 WARN  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds 
and try again.
   [junit4]   2> 3367025 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
   [junit4]   2> 3367026 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
   [junit4]   2> 3367027 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3367028 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using 
configuration from collection addReplicaColl
   [junit4]   2> 3367028 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3367028 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using 
configuration from collection addReplicaColl
   [junit4]   2> 3367029 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:54991/data
   [junit4]   2> 3367029 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3367029 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore 
[[addReplicaColl_shard1_replica1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node2/addReplicaColl_shard1_replica1],
 dataDir=[hdfs://localhost:54991/data/addReplicaColl/core_node1/data/]
   [junit4]   2> 3367029 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:54991/data
   [junit4]   2> 3367029 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3367029 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6aabcf45
   [junit4]   2> 3367029 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore 
[[addReplicaColl_shard2_replica2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node1/addReplicaColl_shard2_replica2],
 dataDir=[hdfs://localhost:54991/data/addReplicaColl/core_node4/data/]
   [junit4]   2> 3367029 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node1/data/snapshot_metadata
   [junit4]   2> 3367029 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6aabcf45
   [junit4]   2> 3367030 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
   [junit4]   2> 3367030 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node4/data/snapshot_metadata
   [junit4]   2> 3367038 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3367041 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica1' using 
configuration from collection addReplicaColl
   [junit4]   2> 3367042 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:54991/data
   [junit4]   2> 3367042 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3367042 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore 
[[addReplicaColl_shard2_replica1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node4/addReplicaColl_shard2_replica1],
 dataDir=[hdfs://localhost:54991/data/addReplicaColl/core_node3/data/]
   [junit4]   2> 3367042 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3367042 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3367042 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6aabcf45
   [junit4]   2> 3367043 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node3/data/snapshot_metadata
   [junit4]   2> 3367044 WARN  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds 
and try again.
   [junit4]   2> 3367047 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3367048 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3367049 WARN  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds 
and try again.
   [junit4]   2> 3367061 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3367061 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3367066 WARN  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds 
and try again.
   [junit4]   2> 3372025 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372026 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node2/data
   [junit4]   2> 3372039 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node2/data/index
   [junit4]   2> 3372045 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3372045 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3372047 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372049 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node4/data
   [junit4]   2> 3372050 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372055 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372055 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node1/data
   [junit4]   2> 3372069 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372069 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node3/data
   [junit4]   2> 3372071 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node4/data/index
   [junit4]   2> 3372073 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node1/data/index
   [junit4]   2> 3372088 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3372089 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3372095 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372098 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3372098 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3372101 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372102 INFO  (IPC Server handler 5 on 54991) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52646 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-396afd20-01b8-4429-b68c-004c3819191a:NORMAL:127.0.0.1:52646|RBW]]}
 size 0
   [junit4]   2> 3372102 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node3/data/index
   [junit4]   2> 3372110 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3372110 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3372118 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3372127 INFO  (IPC Server handler 9 on 54991) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52646 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-6b23e885-f071-4d9d-8c64-d5b6714a73b2:NORMAL:127.0.0.1:52646|FINALIZED]]}
 size 0
   [junit4]   2> 3372141 INFO  (IPC Server handler 9 on 54991) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52646 is 
added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-396afd20-01b8-4429-b68c-004c3819191a:NORMAL:127.0.0.1:52646|RBW]]}
 size 0
   [junit4]   2> 3372166 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3372166 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3372166 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 3372174 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3372174 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3372177 INFO  (IPC Server handler 8 on 54991) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52646 is 
added to blk_1073741828_1004{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-6b23e885-f071-4d9d-8c64-d5b6714a73b2:NORMAL:127.0.0.1:52646|RBW]]}
 size 0
   [junit4]   2> 3372186 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3372186 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3372186 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 3372193 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3372193 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3372193 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 3372194 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3372194 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3372197 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@5547c6df[addReplicaColl_shard1_replica2] main]
   [junit4]   2> 3372198 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3372198 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3372198 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3372199 INFO  
(searcherExecutor-11692-thread-1-processing-n:127.0.0.1:57381_solr 
x:addReplicaColl_shard1_replica2 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:57381_solr c:addReplicaColl s:shard1  
x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica2] Registered new searcher 
Searcher@5547c6df[addReplicaColl_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3372200 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1561735675499249664
   [junit4]   2> 3372205 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3372205 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3372206 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6aba86c0[addReplicaColl_shard2_replica2] main]
   [junit4]   2> 3372207 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3372207 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3372207 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3372208 INFO  
(searcherExecutor-11693-thread-1-processing-n:127.0.0.1:39325_solr 
x:addReplicaColl_shard2_replica2 s:shard2 c:addReplicaColl) 
[n:127.0.0.1:39325_solr c:addReplicaColl s:shard2  
x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore 
[addReplicaColl_shard2_replica2] Registered new searcher 
Searcher@6aba86c0[addReplicaColl_shard2_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3372210 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1561735675509735424
   [junit4]   2> 3372210 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 3372213 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372213 INFO  
(zkCallback-26014-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372213 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372213 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372216 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@54c85cb8[addReplicaColl_shard1_replica1] main]
   [junit4]   2> 3372216 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3372216 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3372216 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3372217 INFO  
(searcherExecutor-11694-thread-1-processing-n:127.0.0.1:33493_solr 
x:addReplicaColl_shard1_replica1 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:33493_solr c:addReplicaColl s:shard1  
x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica1] Registered new searcher 
Searcher@54c85cb8[addReplicaColl_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3372218 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1561735675518124032
   [junit4]   2> 3372218 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard2: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 3372224 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3372224 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3372224 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 3372233 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3372233 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3372239 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@50f7b785[addReplicaColl_shard2_replica1] main]
   [junit4]   2> 3372240 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3372240 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3372241 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3372241 INFO  
(searcherExecutor-11695-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard2_replica1 s:shard2 c:addReplicaColl) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard2  
x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore 
[addReplicaColl_shard2_replica1] Registered new searcher 
Searcher@50f7b785[addReplicaColl_shard2_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3372243 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1561735675544338432
   [junit4]   2> 3372319 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372319 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372319 INFO  
(zkCallback-26014-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372319 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372710 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 3372710 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 3372710 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:57381/solr/addReplicaColl_shard1_replica2/
   [junit4]   2> 3372711 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.PeerSync 
PeerSync: core=addReplicaColl_shard1_replica2 url=http://127.0.0.1:57381/solr 
START replicas=[http://127.0.0.1:33493/solr/addReplicaColl_shard1_replica1/] 
nUpdates=100
   [junit4]   2> 3372711 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.PeerSync 
PeerSync: core=addReplicaColl_shard1_replica2 url=http://127.0.0.1:57381/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 3372713 INFO  (qtp1980360026-166083) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica1] 
o.a.s.c.S.Request [addReplicaColl_shard1_replica1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=1
   [junit4]   2> 3372713 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 3372713 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 3372713 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 3372715 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:57381/solr/addReplicaColl_shard1_replica2/ shard1
   [junit4]   2> 3372719 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 3372719 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 3372719 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:39325/solr/addReplicaColl_shard2_replica2/
   [junit4]   2> 3372719 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.PeerSync 
PeerSync: core=addReplicaColl_shard2_replica2 url=http://127.0.0.1:39325/solr 
START replicas=[http://127.0.0.1:58329/solr/addReplicaColl_shard2_replica1/] 
nUpdates=100
   [junit4]   2> 3372719 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.PeerSync 
PeerSync: core=addReplicaColl_shard2_replica2 url=http://127.0.0.1:39325/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 3372720 INFO  (qtp165421965-166094) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica1] 
o.a.s.c.S.Request [addReplicaColl_shard2_replica1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 3372721 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 3372721 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 3372721 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 3372723 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:39325/solr/addReplicaColl_shard2_replica2/ shard2
   [junit4]   2> 3372825 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372825 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372825 INFO  
(zkCallback-26014-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372825 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372866 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 3372868 INFO  (qtp866721603-166068) [n:127.0.0.1:57381_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2}
 status=0 QTime=6899
   [junit4]   2> 3372873 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 3372874 INFO  (qtp790760885-166059) [n:127.0.0.1:39325_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2}
 status=0 QTime=6890
   [junit4]   2> 3372976 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372976 INFO  
(zkCallback-26014-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372976 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3372976 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3373224 INFO  (qtp1980360026-166081) [n:127.0.0.1:33493_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2}
 status=0 QTime=7254
   [junit4]   2> 3373247 INFO  (qtp165421965-166090) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2}
 status=0 QTime=7274
   [junit4]   2> 3373249 INFO  (qtp866721603-166071) [n:127.0.0.1:57381_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> 3373350 INFO  
(zkCallback-26014-thread-3-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3373350 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3373350 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3373350 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3373861 INFO  
(OverseerCollectionConfigSetProcessor-97608479083790344-127.0.0.1:39325_solr-n_0000000000)
 [n:127.0.0.1:39325_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> 3374249 INFO  (qtp866721603-166071) [n:127.0.0.1:57381_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2}
 status=0 QTime=8401
   [junit4]   2> 3374253 INFO  (qtp866721603-166072) [n:127.0.0.1:57381_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with 
params 
node=127.0.0.1:58329_solr&action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 3374255 INFO  
(OverseerThreadFactory-11683-thread-3-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.AddReplicaCmd addReplica() : {
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "node":"127.0.0.1:58329_solr",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "operation":"addreplica"}
   [junit4]   2> 3374255 INFO  
(OverseerThreadFactory-11683-thread-3-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.AddReplicaCmd Node Identified 
127.0.0.1:58329_solr for creating new replica
   [junit4]   2> 3374257 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica3&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 3374360 INFO  
(zkCallback-26020-thread-1-processing-n:127.0.0.1:58329_solr) 
[n:127.0.0.1:58329_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3374360 INFO  
(zkCallback-26019-thread-1-processing-n:127.0.0.1:57381_solr) 
[n:127.0.0.1:57381_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3374360 INFO  
(zkCallback-26014-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3374360 INFO  
(zkCallback-26018-thread-1-processing-n:127.0.0.1:33493_solr) 
[n:127.0.0.1:33493_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 3375263 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 3375269 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica3] Schema name=minimal
   [junit4]   2> 3375271 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3375272 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica3' using 
configuration from collection addReplicaColl
   [junit4]   2> 3375272 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:54991/data
   [junit4]   2> 3375273 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 3375273 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] o.a.s.c.SolrCore 
[[addReplicaColl_shard1_replica3] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-001/node4/addReplicaColl_shard1_replica3],
 dataDir=[hdfs://localhost:54991/data/addReplicaColl/core_node5/data/]
   [junit4]   2> 3375273 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6aabcf45
   [junit4]   2> 3375273 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node5/data/snapshot_metadata
   [junit4]   2> 3375278 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3375278 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3375280 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3375281 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node5/data
   [junit4]   2> 3375340 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:54991/data/addReplicaColl/core_node5/data/index
   [junit4]   2> 3375416 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 3375417 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[4194304] will allocate [1] slabs and use ~[4194304] bytes
   [junit4]   2> 3375418 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 3375457 INFO  (IPC Server handler 3 on 54991) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:52646 is 
added to blk_1073741829_1005{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-396afd20-01b8-4429-b68c-004c3819191a:NORMAL:127.0.0.1:52646|RBW]]}
 size 0
   [junit4]   2> 3375529 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 3375529 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3375529 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 3375537 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3375537 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3375570 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3f6b8136[addReplicaColl_shard1_replica3] main]
   [junit4]   2> 3375570 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3375570 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3375571 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3375572 INFO  
(searcherExecutor-11712-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1  
x:addReplicaColl_shard1_replica3] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica3] Registered new searcher 
Searcher@3f6b8136[addReplicaColl_shard1_replica3] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3375573 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1561735679036096512
   [junit4]   2> 3375576 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.c.ZkController Core needs to recover:addReplicaColl_shard1_replica3
   [junit4]   2> 3375583 INFO  
(updateExecutor-26015-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.u.DefaultSolrCoreState Running recovery
   [junit4]   2> 3375583 INFO  (qtp165421965-166093) [n:127.0.0.1:58329_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica3] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica3&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2}
 status=0 QTime=1326
   [junit4]   2> 3375589 INFO  
(recoveryExecutor-26016-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl r:core_node5) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.c.RecoveryStrategy Starting recovery 
process. recoveringAfterStartup=true
   [junit4]   2> 3375590 INFO  
(recoveryExecutor-26016-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl r:core_node5) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.c.RecoveryStrategy ###### 
startupVersions=[[]]
   [junit4]   2> 3375592 INFO  (qtp866721603-166072) [n:127.0.0.1:57381_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={node=127.0.0.1:58329_solr&action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2}
 status=0 QTime=1338
   [junit4]   2> 3375594 INFO  (qtp866721603-166074) [n:127.0.0.1:57381_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with 
params 
action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&property.instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-003
 and sendToOCPQueue=true
   [junit4]   2> 3375596 INFO  
(OverseerCollectionConfigSetProcessor-97608479083790344-127.0.0.1:39325_solr-n_0000000000)
 [n:127.0.0.1:39325_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> 3375596 INFO  
(recoveryExecutor-26016-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl r:core_node5) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.c.RecoveryStrategy Begin buffering 
updates. core=[addReplicaColl_shard1_replica3]
   [junit4]   2> 3375596 INFO  
(recoveryExecutor-26016-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl r:core_node5) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.u.UpdateLog Starting to buffer updates. 
HDFSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 3375596 INFO  
(recoveryExecutor-26016-thread-1-processing-n:127.0.0.1:58329_solr 
x:addReplicaColl_shard1_replica3 s:shard1 c:addReplicaColl r:core_node5) 
[n:127.0.0.1:58329_solr c:addReplicaColl s:shard1 r:core_node5 
x:addReplicaColl_shard1_replica3] o.a.s.c.RecoveryStrategy Publishing state of 
core [addReplicaColl_shard1_replica3] as recovering, leader is 
[http://127.0.0.1:57381/solr/addReplicaColl_shard1_replica2/] and I am 
[http://127.0.0.1:58329/solr/addReplicaColl_shard1_replica3/]
   [junit4]   2> 3375596 INFO  
(OverseerThreadFactory-11683-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.AddReplicaCmd addReplica() : {
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   
"property.instanceDir":"/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001/tempDir-003",
   [junit4]   2>   "operation":"addreplica"}
   [junit4]   2> 3375596 INFO  
(OverseerThreadFactory-11683-thread-4-processing-n:127.0.0.1:39325_solr) 
[n:127.0.0.1:39325_solr    ] o.a.s.c.AddReplicaCmd Node Identified 
127.0.0.1:57381_solr for creating new replica
   [junit4]   2> 3375600 INFO  (qtp866721603-166073) [n:127.0.0.1:57381_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica4&action=CREATE&colle

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

ics2.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:204)
   [junit4]   2>        at 
org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.teardownClass(HdfsCollectionsAPIDistributedZkTest.java:55)
   [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:368)
   [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>        ... 53 more
   [junit4]   2> 3468625 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60357 60357
   [junit4]   2> 3468626 INFO  
(SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[8DD03C4F06B63688]-worker) [    
] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_8DD03C4F06B63688-001
   [junit4]   2> Mar 13, 2017 6:41:39 AM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 18 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{_version_=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
id=PostingsFormat(name=Memory)}, docValues:{}, maxPointsInLeafNode=1476, 
maxMBSortInHeap=7.7351353250357455, sim=RandomSimilarity(queryNorm=false): {}, 
locale=bg-BG, timezone=Canada/Eastern
   [junit4]   2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 
1.8.0_121 (64-bit)/cpus=4,threads=2,free=102088088,total=524812288
   [junit4]   2> NOTE: All tests run in this JVM: [TestNoOpRegenerator, 
TestAnalyzedSuggestions, SparseHLLTest, TestConfigSets, AddBlockUpdateTest, 
SuggestComponentTest, TestQuerySenderListener, TemplateUpdateProcessorTest, 
TestConfigOverlay, TestRangeQuery, TestTestInjection, TestCrossCoreJoin, 
TestFastWriter, TestHighlightDedupGrouping, TestDynamicFieldCollectionResource, 
TestPointFields, DeleteNodeTest, TestStressLiveNodes, SolrCloudReportersTest, 
TestFieldResource, SpatialRPTFieldTypeTest, HdfsRecoverLeaseTest, 
BlockDirectoryTest, TestLazyCores, TestMinMaxOnMultiValuedField, TestLRUCache, 
SolrRequestParserTest, TestCSVLoader, TestReplicationHandler, SolrCoreTest, 
TestDistributedSearch, TestPushWriter, TestSchemaNameResource, 
TestPivotHelperCode, DataDrivenBlockJoinTest, TestRTGBase, 
TestSolrQueryResponse, ParsingFieldUpdateProcessorsTest, TestApiFramework, 
TestDefaultStatsCache, DistributedQueryElevationComponentTest, 
NotRequiredUniqueKeyTest, CurrencyFieldOpenExchangeTest, DateMathParserTest, 
TestRealTimeGet, ReplaceNodeTest, HdfsLockFactoryTest, TestSimpleQParserPlugin, 
MinimalSchemaTest, TestBinaryResponseWriter, ReturnFieldsTest, 
SignatureUpdateProcessorFactoryTest, TestSubQueryTransformerCrossCore, 
TestNumericTerms32, BigEndianAscendingWordSerializerTest, 
DistribJoinFromCollectionTest, HighlighterMaxOffsetTest, TestManagedSchema, 
BasicAuthStandaloneTest, EnumFieldTest, HdfsBasicDistributedZk2Test, 
QueryEqualityTest, CoreSorterTest, TestShardHandlerFactory, 
TestUseDocValuesAsStored, TestPKIAuthenticationPlugin, TestFieldCacheReopen, 
RequiredFieldsTest, UUIDFieldTest, FastVectorHighlighterTest, 
TestSolrCoreParser, DisMaxRequestHandlerTest, TestSuggestSpellingConverter, 
AnalyticsQueryTest, TestDownShardTolerantSearch, CustomCollectionTest, 
DistributedQueryComponentCustomSortTest, ChangedSchemaMergeTest, 
TestHdfsBackupRestoreCore, PathHierarchyTokenizerFactoryTest, 
TestInPlaceUpdatesDistrib, BlobRepositoryCloudTest, NumericFieldsTest, 
TestGeoJSONResponseWriter, TestConfigSetsAPI, LeaderElectionContextKeyTest, 
TestGraphTermsQParserPlugin, TestClassNameShortening, 
TlogReplayBufferedWhileIndexingTest, TestDocBasedVersionConstraints, 
TestSolrDeletionPolicy2, ShardSplitTest, TestFreeTextSuggestions, 
BasicDistributedZkTest, JvmMetricsTest, TestMacros, MultiTermTest, 
CopyFieldTest, TestLFUCache, BJQParserTest, StandardRequestHandlerTest, 
TestSolrCoreProperties, TestJoin, SpellPossibilityIteratorTest, 
DocumentAnalysisRequestHandlerTest, TestLegacyNumericRangeQueryBuilder, 
TestRestoreCore, HdfsSyncSliceTest, WrapperMergePolicyFactoryTest, 
MultiThreadedOCPTest, SharedFSAutoReplicaFailoverUtilsTest, 
SimpleCollectionCreateDeleteTest, SolrCLIZkUtilsTest, SolrXmlInZkTest, 
TestAuthenticationFramework, TestCloudDeleteByQuery, TestCloudInspectUtil, 
TestCloudPivotFacet, TestCloudRecovery, TestConfigSetsAPIExclusivity, 
TestCryptoKeys, TestDistribDocBasedVersion, TestExclusionRuleCollectionAccess, 
TestHdfsCloudBackupRestore, TestLocalFSCloudBackupRestore, 
TestMiniSolrCloudClusterSSL, TestRandomRequestDistribution, 
TestRebalanceLeaders, TestRequestForwarding, TestSSLRandomization, 
TestSizeLimitedDistributedMap, TestSolrCloudWithSecureImpersonation, 
TestStressInPlaceUpdates, HdfsChaosMonkeyNothingIsSafeTest, 
HdfsChaosMonkeySafeLeaderTest, HdfsCollectionsAPIDistributedZkTest]
   [junit4] Completed [553/695 (1!)] on J0 in 115.28s, 20 tests, 1 failure <<< 
FAILURES!

[...truncated 63072 lines...]


---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to