Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4066/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC

4 tests failed.
FAILED:  org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest.test

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
        at __randomizedtesting.SeedInfo.seed([4D6AF2FB59880323]:0)


FAILED:  
junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest

Error Message:
Suite timeout exceeded (>= 7200000 msec).

Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
        at __randomizedtesting.SeedInfo.seed([4D6AF2FB59880323]:0)


FAILED:  org.apache.solr.cloud.CollectionsAPISolrJTest.testCloudInfoInCoreStatus

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([4D6AF2FB59880323:6D2C65D2A15BBE0D]:0)
        at org.junit.Assert.fail(Assert.java:92)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertTrue(Assert.java:54)
        at 
org.apache.solr.cloud.CollectionsAPISolrJTest.testCloudInfoInCoreStatus(CollectionsAPISolrJTest.java:105)
        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:748)


FAILED:  org.apache.solr.cloud.MultiThreadedOCPTest.test

Error Message:
Task 3001 did not complete, final state: FAILED expected same:<COMPLETED> was 
not:<FAILED>

Stack Trace:
java.lang.AssertionError: Task 3001 did not complete, final state: FAILED 
expected same:<COMPLETED> was not:<FAILED>
        at 
__randomizedtesting.SeedInfo.seed([4D6AF2FB59880323:C53ECD21F7746EDB]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.failNotSame(Assert.java:641)
        at org.junit.Assert.assertSame(Assert.java:580)
        at 
org.apache.solr.cloud.MultiThreadedOCPTest.testDeduplicationOfSubmittedTasks(MultiThreadedOCPTest.java:226)
        at 
org.apache.solr.cloud.MultiThreadedOCPTest.test(MultiThreadedOCPTest.java:64)
        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 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
        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:748)




Build Log:
[...truncated 11595 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPISolrJTest
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/init-core-data-001
   [junit4]   2> 857526 WARN  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8
   [junit4]   2> 857527 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 857530 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) 
w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 857531 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001
   [junit4]   2> 857531 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 857531 INFO  (Thread-1459) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 857531 INFO  (Thread-1459) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 857534 ERROR (Thread-1459) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 857633 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:60432
   [junit4]   2> 857661 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 857661 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 857661 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 857661 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 857665 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@3dced72{/solr,null,AVAILABLE}
   [junit4]   2> 857665 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@2296b73d{/solr,null,AVAILABLE}
   [junit4]   2> 857665 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@2edd41a6{/solr,null,AVAILABLE}
   [junit4]   2> 857667 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@2e4c2b95{/solr,null,AVAILABLE}
   [junit4]   2> 857669 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@38434741{HTTP/1.1,[http/1.1]}{127.0.0.1:60434}
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.e.j.s.Server Started @861183ms
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60434}
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1105d1f1{HTTP/1.1,[http/1.1]}{127.0.0.1:60435}
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.e.j.s.Server Started @861184ms
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60435}
   [junit4]   2> 857670 ERROR (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 857670 ERROR (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@2ce3da7b{HTTP/1.1,[http/1.1]}{127.0.0.1:60437}
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.e.j.s.Server Started @861184ms
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60437}
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 857671 ERROR (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-12T02:25:56.871Z
   [junit4]   2> 857670 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@3f721969{HTTP/1.1,[http/1.1]}{127.0.0.1:60436}
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.e.j.s.Server Started @861185ms
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60436}
   [junit4]   2> 857671 ERROR (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-12T02:25:56.871Z
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 857671 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-12T02:25:56.871Z
   [junit4]   2> 857672 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 857672 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 857672 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 857672 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-12T02:25:56.872Z
   [junit4]   2> 857674 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 857674 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 857674 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 857674 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 857683 INFO  (jetty-launcher-1523-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60432/solr
   [junit4]   2> 857684 INFO  (jetty-launcher-1523-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60432/solr
   [junit4]   2> 857685 INFO  (jetty-launcher-1523-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60432/solr
   [junit4]   2> 857687 INFO  (jetty-launcher-1523-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60432/solr
   [junit4]   2> 857729 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 857730 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 857729 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 857729 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 857731 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:60434_solr
   [junit4]   2> 857733 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60435_solr
   [junit4]   2> 857733 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60436_solr
   [junit4]   2> 857733 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60437_solr
   [junit4]   2> 857733 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.Overseer Overseer 
(id=98122750802919434-127.0.0.1:60434_solr-n_0000000000) starting
   [junit4]   2> 857755 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60434_solr
   [junit4]   2> 857773 INFO  
(zkCallback-1544-thread-1-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 857773 INFO  
(zkCallback-1545-thread-1-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 857774 INFO  
(zkCallback-1543-thread-1-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 857774 INFO  
(zkCallback-1542-thread-1-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 857862 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857864 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857865 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857866 INFO  (jetty-launcher-1523-thread-3) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/.
   [junit4]   2> 857868 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60437.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857869 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60436.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857872 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60436.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857872 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60436.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857879 INFO  (jetty-launcher-1523-thread-1) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node1/.
   [junit4]   2> 857881 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60437.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857881 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60437.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857882 INFO  (jetty-launcher-1523-thread-4) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node4/.
   [junit4]   2> 857906 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60435.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857912 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60435.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857912 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60435.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 857913 INFO  (jetty-launcher-1523-thread-2) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node2/.
   [junit4]   2> 857963 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 857965 INFO  
(SUITE-CollectionsAPISolrJTest-seed#[4D6AF2FB59880323]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:60432/solr ready
   [junit4]   2> 857996 INFO  
(TEST-CollectionsAPISolrJTest.testList-seed#[4D6AF2FB59880323]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testList
   [junit4]   2> 857999 INFO  (qtp247977526-8141) [n:127.0.0.1:60437_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params 
action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 857999 INFO  (qtp247977526-8141) [n:127.0.0.1:60437_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={action=LIST&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 857999 INFO  
(TEST-CollectionsAPISolrJTest.testList-seed#[4D6AF2FB59880323]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending testList
   [junit4]   2> 858022 INFO  
(TEST-CollectionsAPISolrJTest.testCreateAndDeleteShard-seed#[4D6AF2FB59880323]) 
[    ] o.a.s.SolrTestCaseJ4 ###Starting testCreateAndDeleteShard
   [junit4]   2> 858022 INFO  (qtp247977526-8142) [n:127.0.0.1:60437_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
pullReplicas=1&shards=shardA,shardB&replicationFactor=1&collection.configName=conf&maxShardsPerNode=3&name=solrj_implicit&router.name=implicit&nrtReplicas=1&action=CREATE&tlogReplicas=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 858025 INFO  
(OverseerThreadFactory-3487-thread-1-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
solrj_implicit
   [junit4]   2> 858135 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_p1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 858137 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_p1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 858137 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 858137 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_n1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 858138 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_t1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 858135 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_n1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 858139 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 858137 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_t1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 858139 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 858139 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 858262 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 858262 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 858262 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 858262 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859174 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859178 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859178 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859182 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859197 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859197 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859204 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.s.IndexSchema [solrj_implicit_shardA_replica_p1] Schema name=minimal
   [junit4]   2> 859204 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.s.IndexSchema [solrj_implicit_shardA_replica_t1] Schema name=minimal
   [junit4]   2> 859206 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859207 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardA_replica_p1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859207 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60435.solr.core.solrj_implicit.shardA.replica_p1' (registry 
'solr.core.solrj_implicit.shardA.replica_p1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859207 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859207 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] o.a.s.c.SolrCore 
[[solrj_implicit_shardA_replica_p1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node2/solrj_implicit_shardA_replica_p1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node2/./solrj_implicit_shardA_replica_p1/data/]
   [junit4]   2> 859208 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.s.IndexSchema [solrj_implicit_shardB_replica_p1] Schema name=minimal
   [junit4]   2> 859209 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859209 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardB_replica_p1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859209 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.core.solrj_implicit.shardB.replica_p1' (registry 
'solr.core.solrj_implicit.shardB.replica_p1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859209 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859210 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] o.a.s.c.SolrCore 
[[solrj_implicit_shardB_replica_p1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/solrj_implicit_shardB_replica_p1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/./solrj_implicit_shardB_replica_p1/data/]
   [junit4]   2> 859210 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.s.IndexSchema [solrj_implicit_shardA_replica_n1] Schema name=minimal
   [junit4]   2> 859211 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859212 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardA_replica_n1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859212 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60436.solr.core.solrj_implicit.shardA.replica_n1' (registry 
'solr.core.solrj_implicit.shardA.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859212 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859212 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] o.a.s.c.SolrCore 
[[solrj_implicit_shardA_replica_n1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node1/solrj_implicit_shardA_replica_n1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node1/./solrj_implicit_shardA_replica_n1/data/]
   [junit4]   2> 859213 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.s.IndexSchema [solrj_implicit_shardB_replica_t1] Schema name=minimal
   [junit4]   2> 859214 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859214 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardB_replica_t1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859215 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60436.solr.core.solrj_implicit.shardB.replica_t1' (registry 
'solr.core.solrj_implicit.shardB.replica_t1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859215 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859215 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] o.a.s.c.SolrCore 
[[solrj_implicit_shardB_replica_t1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node1/solrj_implicit_shardB_replica_t1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node1/./solrj_implicit_shardB_replica_t1/data/]
   [junit4]   2> 859216 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859216 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardA_replica_t1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859216 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.core.solrj_implicit.shardA.replica_t1' (registry 
'solr.core.solrj_implicit.shardA.replica_t1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859216 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859216 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] o.a.s.c.SolrCore 
[[solrj_implicit_shardA_replica_t1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/solrj_implicit_shardA_replica_t1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/./solrj_implicit_shardA_replica_t1/data/]
   [junit4]   2> 859218 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.s.IndexSchema [solrj_implicit_shardB_replica_n1] Schema name=minimal
   [junit4]   2> 859219 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859219 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardB_replica_n1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 859220 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60437.solr.core.solrj_implicit.shardB.replica_n1' (registry 
'solr.core.solrj_implicit.shardB.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 859220 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 859220 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] o.a.s.c.SolrCore 
[[solrj_implicit_shardB_replica_n1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node4/solrj_implicit_shardB_replica_n1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node4/./solrj_implicit_shardB_replica_n1/data/]
   [junit4]   2> 859333 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859333 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859334 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 859334 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859336 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859336 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859338 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@755dbd1[solrj_implicit_shardA_replica_p1] main]
   [junit4]   2> 859340 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@173ab46c[solrj_implicit_shardA_replica_n1] main]
   [junit4]   2> 859349 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 859349 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859351 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859351 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859354 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859354 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859356 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 859356 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859358 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859358 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859358 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 859358 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859359 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859359 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859359 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859359 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859360 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859360 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859360 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859361 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859361 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1569964014762459136
   [junit4]   2> 859362 INFO  
(searcherExecutor-3496-thread-1-processing-n:127.0.0.1:60435_solr 
x:solrj_implicit_shardA_replica_p1 s:shardA c:solrj_implicit) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.c.SolrCore 
[solrj_implicit_shardA_replica_p1] Registered new searcher 
Searcher@755dbd1[solrj_implicit_shardA_replica_p1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859362 INFO  
(searcherExecutor-3498-thread-1-processing-n:127.0.0.1:60436_solr 
x:solrj_implicit_shardA_replica_n1 s:shardA c:solrj_implicit) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_n1] o.a.s.c.SolrCore 
[solrj_implicit_shardA_replica_n1] Registered new searcher 
Searcher@173ab46c[solrj_implicit_shardA_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859362 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@72be1bd5[solrj_implicit_shardA_replica_t1] main]
   [junit4]   2> 859363 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.c.ZkController solrj_implicit_shardA_replica_p1 starting background 
replication from leader
   [junit4]   2> 859363 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 859364 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859365 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859366 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859369 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@14679610[solrj_implicit_shardB_replica_n1] main]
   [junit4]   2> 859370 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1c0604e2[solrj_implicit_shardB_replica_p1] main]
   [junit4]   2> 859370 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859371 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859372 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859372 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1569964014773993472
   [junit4]   2> 859373 INFO  
(searcherExecutor-3501-thread-1-processing-n:127.0.0.1:60437_solr 
x:solrj_implicit_shardB_replica_n1 s:shardB c:solrj_implicit) 
[n:127.0.0.1:60437_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_n1] o.a.s.c.SolrCore 
[solrj_implicit_shardB_replica_n1] Registered new searcher 
Searcher@14679610[solrj_implicit_shardB_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859373 INFO  
(searcherExecutor-3500-thread-1-processing-n:127.0.0.1:60434_solr 
x:solrj_implicit_shardA_replica_t1 s:shardA c:solrj_implicit) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.c.SolrCore 
[solrj_implicit_shardA_replica_t1] Registered new searcher 
Searcher@72be1bd5[solrj_implicit_shardA_replica_t1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859373 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1569964014775042048
   [junit4]   2> 859375 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shardA: total=2 found=1 timeoutin=9998ms
   [junit4]   2> 859376 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859377 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859378 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859379 INFO  
(searcherExecutor-3497-thread-1-processing-n:127.0.0.1:60434_solr 
x:solrj_implicit_shardB_replica_p1 s:shardB c:solrj_implicit) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_p1] o.a.s.c.SolrCore 
[solrj_implicit_shardB_replica_p1] Registered new searcher 
Searcher@1c0604e2[solrj_implicit_shardB_replica_p1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859379 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 859380 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.c.ZkController solrj_implicit_shardB_replica_p1 starting background 
replication from leader
   [junit4]   2> 859380 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 859381 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shardB: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 859382 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 859382 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@2dabd005[solrj_implicit_shardB_replica_t1] main]
   [junit4]   2> 859384 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 859385 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859385 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859385 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1569964014787624960
   [junit4]   2> 859386 INFO  
(searcherExecutor-3499-thread-1-processing-n:127.0.0.1:60436_solr 
x:solrj_implicit_shardB_replica_t1 s:shardB c:solrj_implicit) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.c.SolrCore 
[solrj_implicit_shardB_replica_t1] Registered new searcher 
Searcher@2dabd005[solrj_implicit_shardB_replica_t1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859486 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859486 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859486 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859486 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859885 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 859885 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 859885 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 859885 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 859885 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:60437/solr/solrj_implicit_shardB_replica_n1/
   [junit4]   2> 859885 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:60436/solr/solrj_implicit_shardA_replica_n1/
   [junit4]   2> 859886 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] o.a.s.u.PeerSync 
PeerSync: core=solrj_implicit_shardA_replica_n1 url=http://127.0.0.1:60436/solr 
START replicas=[http://127.0.0.1:60434/solr/solrj_implicit_shardA_replica_t1/] 
nUpdates=100
   [junit4]   2> 859886 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] o.a.s.u.PeerSync 
PeerSync: core=solrj_implicit_shardB_replica_n1 url=http://127.0.0.1:60437/solr 
START replicas=[http://127.0.0.1:60436/solr/solrj_implicit_shardB_replica_t1/] 
nUpdates=100
   [junit4]   2> 859886 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] o.a.s.u.PeerSync 
PeerSync: core=solrj_implicit_shardA_replica_n1 url=http://127.0.0.1:60436/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 859886 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] o.a.s.u.PeerSync 
PeerSync: core=solrj_implicit_shardB_replica_n1 url=http://127.0.0.1:60437/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 859887 INFO  (qtp617990520-8136) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA r:core_node2 x:solrj_implicit_shardA_replica_t1] 
o.a.s.c.S.Request [solrj_implicit_shardA_replica_t1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 859887 INFO  (qtp1450273452-8150) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB r:core_node6 x:solrj_implicit_shardB_replica_t1] 
o.a.s.c.S.Request [solrj_implicit_shardB_replica_t1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 859888 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 859888 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 859888 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 859888 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 859888 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 859888 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 859896 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:60436/solr/solrj_implicit_shardA_replica_n1/ shardA
   [junit4]   2> 859897 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:60437/solr/solrj_implicit_shardB_replica_n1/ shardB
   [junit4]   2> 860012 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860012 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860012 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860012 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860015 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Replica core_node3 is 
leader but it's state is down, skipping replication
   [junit4]   2> 860071 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 860071 INFO  (indexFetcher-3527-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_p1] o.a.s.h.IndexFetcher Replica core_node4 is 
leader but it's state is down, skipping replication
   [junit4]   2> 860071 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 860074 INFO  (qtp1450273452-8149) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_n1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1937
   [junit4]   2> 860076 INFO  (qtp247977526-8143) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_n1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1940
   [junit4]   2> 860182 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860182 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860182 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860182 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860381 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.c.ZkController solrj_implicit_shardA_replica_t1 starting background 
replication from leader
   [junit4]   2> 860381 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 860382 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 860382 INFO  (indexFetcher-3529-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.h.IndexFetcher Updated masterUrl to 
http://127.0.0.1:60436/solr/solrj_implicit_shardA_replica_n1/
   [junit4]   2> 860384 INFO  (qtp1450273452-8152) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA r:core_node3 x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.S.Request [solrj_implicit_shardA_replica_n1]  webapp=/solr 
path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 860384 INFO  (indexFetcher-3529-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 860384 INFO  (indexFetcher-3529-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 860384 INFO  (indexFetcher-3529-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 860384 INFO  (indexFetcher-3529-thread-1) 
[n:127.0.0.1:60434_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_t1] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 860386 INFO  (qtp617990520-8134) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_t1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_t1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=TLOG}
 status=0 QTime=2247
   [junit4]   2> 860388 INFO  (qtp862287950-8125) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardA  x:solrj_implicit_shardA_replica_p1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardA_replica_p1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardA&wt=javabin&version=2&replicaType=PULL}
 status=0 QTime=2251
   [junit4]   2> 860388 INFO  (qtp617990520-8132) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_p1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_p1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=PULL}
 status=0 QTime=2252
   [junit4]   2> 860390 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.c.ZkController solrj_implicit_shardB_replica_t1 starting background 
replication from leader
   [junit4]   2> 860390 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.c.ReplicateFromLeader Will start replication from leader with poll 
interval: 00:00:03
   [junit4]   2> 860391 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 860391 INFO  (indexFetcher-3531-thread-1) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.h.IndexFetcher Updated masterUrl to 
http://127.0.0.1:60437/solr/solrj_implicit_shardB_replica_n1/
   [junit4]   2> 860392 INFO  (qtp247977526-8144) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardB r:core_node4 x:solrj_implicit_shardB_replica_n1] 
o.a.s.c.S.Request [solrj_implicit_shardB_replica_n1]  webapp=/solr 
path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 860392 INFO  (indexFetcher-3531-thread-1) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 860392 INFO  (indexFetcher-3531-thread-1) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 860392 INFO  (indexFetcher-3531-thread-1) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 860392 INFO  (indexFetcher-3531-thread-1) 
[n:127.0.0.1:60436_solr c:solrj_implicit s:shardB  
x:solrj_implicit_shardB_replica_t1] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 860393 INFO  (qtp1450273452-8148) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardB  x:solrj_implicit_shardB_replica_t1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=solrj_implicit_shardB_replica_t1&action=CREATE&numShards=2&collection=solrj_implicit&shard=shardB&wt=javabin&version=2&replicaType=TLOG}
 status=0 QTime=2256
   [junit4]   2> 860396 INFO  (qtp247977526-8142) [n:127.0.0.1:60437_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> 860500 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860500 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860500 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860500 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861401 INFO  (qtp247977526-8142) [n:127.0.0.1:60437_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={pullReplicas=1&shards=shardA,shardB&replicationFactor=1&collection.configName=conf&maxShardsPerNode=3&name=solrj_implicit&router.name=implicit&nrtReplicas=1&action=CREATE&tlogReplicas=1&wt=javabin&version=2}
 status=0 QTime=3379
   [junit4]   2> 861405 INFO  (qtp247977526-8146) [n:127.0.0.1:60437_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :createshard with params 
action=CREATESHARD&collection=solrj_implicit&shard=shardC&wt=javabin&version=2 
and sendToOCPQueue=true
   [junit4]   2> 861407 INFO  
(OverseerThreadFactory-3487-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CreateShardCmd Create shard invoked: {
   [junit4]   2>   "collection":"solrj_implicit",
   [junit4]   2>   "shard":"shardC",
   [junit4]   2>   "operation":"createshard"}
   [junit4]   2> 861407 INFO  
(OverseerCollectionConfigSetProcessor-98122750802919434-127.0.0.1:60434_solr-n_0000000000)
 [n:127.0.0.1:60434_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> 861513 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861513 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861513 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861513 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861618 INFO  
(OverseerThreadFactory-3487-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CreateShardCmd Creating replica 
solrj_implicit_shardC_replica_n1 as part of slice shardC of collection 
solrj_implicit on 127.0.0.1:60437_solr
   [junit4]   2> 861619 INFO  
(OverseerThreadFactory-3487-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CreateShardCmd Creating replica 
solrj_implicit_shardC_replica_t1 as part of slice shardC of collection 
solrj_implicit on 127.0.0.1:60435_solr
   [junit4]   2> 861619 INFO  
(OverseerThreadFactory-3487-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.CreateShardCmd Creating replica 
solrj_implicit_shardC_replica_p1 as part of slice shardC of collection 
solrj_implicit on 127.0.0.1:60434_solr
   [junit4]   2> 861619 INFO  (qtp247977526-8129) [n:127.0.0.1:60437_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&name=solrj_implicit_shardC_replica_n1&action=CREATE&numShards=1&collection=solrj_implicit&shard=shardC&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 861619 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&name=solrj_implicit_shardC_replica_t1&action=CREATE&numShards=1&collection=solrj_implicit&shard=shardC&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 861620 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&name=solrj_implicit_shardC_replica_p1&action=CREATE&numShards=1&collection=solrj_implicit&shard=shardC&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 861732 INFO  
(zkCallback-1544-thread-2-processing-n:127.0.0.1:60435_solr) 
[n:127.0.0.1:60435_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861732 INFO  
(zkCallback-1545-thread-2-processing-n:127.0.0.1:60436_solr) 
[n:127.0.0.1:60436_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861732 INFO  
(zkCallback-1543-thread-2-processing-n:127.0.0.1:60434_solr) 
[n:127.0.0.1:60434_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861732 INFO  
(zkCallback-1542-thread-2-processing-n:127.0.0.1:60437_solr) 
[n:127.0.0.1:60437_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/solrj_implicit/state.json] for collection [solrj_implicit] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 862580 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Last replication 
failed, so I'll force replication
   [junit4]   2> 862580 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Updated masterUrl to 
http://127.0.0.1:60436/solr/solrj_implicit_shardA_replica_n1/
   [junit4]   2> 862581 INFO  (qtp1450273452-8153) [n:127.0.0.1:60436_solr 
c:solrj_implicit s:shardA r:core_node3 x:solrj_implicit_shardA_replica_n1] 
o.a.s.c.S.Request [solrj_implicit_shardA_replica_n1]  webapp=/solr 
path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.h.IndexFetcher New index in Master. 
Deleting mine...
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 862582 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.u.SolrIndexWriter Calling 
setCommitData with IW:org.apache.solr.update.SolrIndexWriter@38b2fc02 
commitCommandVersion:0
   [junit4]   2> 862585 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.s.SolrIndexSearcher Opening 
[Searcher@4c87cfab[solrj_implicit_shardA_replica_p1] main]
   [junit4]   2> 862585 INFO  (indexFetcher-3525-thread-1) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 862587 INFO  
(searcherExecutor-3496-thread-1-processing-n:127.0.0.1:60435_solr 
x:solrj_implicit_shardA_replica_p1 s:shardA c:solrj_implicit) 
[n:127.0.0.1:60435_solr c:solrj_implicit s:shardA  
x:solrj_implicit_shardA_replica_p1] o.a.s.c.SolrCore 
[solrj_implicit_shardA_replica_p1] Registered new searcher 
Searcher@4c87cfab[solrj_implicit_shardA_replica_p1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 862659 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 862659 INFO  (qtp247977526-8129) [n:127.0.0.1:60437_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 862690 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 862695 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] 
o.a.s.s.IndexSchema [solrj_implicit_shardC_replica_p1] Schema name=minimal
   [junit4]   2> 862695 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] 
o.a.s.s.IndexSchema [solrj_implicit_shardC_replica_t1] Schema name=minimal
   [junit4]   2> 862698 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 862698 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 862698 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardC_replica_t1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 862698 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] 
o.a.s.c.CoreContainer Creating SolrCore 'solrj_implicit_shardC_replica_p1' 
using configuration from collection solrj_implicit, trusted=true
   [junit4]   2> 862698 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60434.solr.core.solrj_implicit.shardC.replica_p1' (registry 
'solr.core.solrj_implicit.shardC.replica_p1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 862698 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60435.solr.core.solrj_implicit.shardC.replica_t1' (registry 
'solr.core.solrj_implicit.shardC.replica_t1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@261f2145
   [junit4]   2> 862698 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 862698 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 862698 INFO  (qtp617990520-8137) [n:127.0.0.1:60434_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_p1] o.a.s.c.SolrCore 
[[solrj_implicit_shardC_replica_p1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/solrj_implicit_shardC_replica_p1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node3/./solrj_implicit_shardC_replica_p1/data/]
   [junit4]   2> 862698 INFO  (qtp862287950-8126) [n:127.0.0.1:60435_solr 
c:solrj_implicit s:shardC  x:solrj_implicit_shardC_replica_t1] o.a.s.c.SolrCore 
[[solrj_implicit_shardC_replica_t1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node2/solrj_implicit_shardC_replica_t1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPISolrJTest_4D6AF2FB59880323-001/tempDir-001/node2/./solrj_implicit_shardC_replica_t1/data/]
   [

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

t4]   2>         at 
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2>   20) Thread[id=12994, name=commitScheduler-5509-thread-1, 
state=WAITING, group=TGRP-ChaosMonkeySafeLeaderWithPullReplicasTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at 
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2>   21) Thread[id=13113, name=searcherExecutor-5572-thread-1, 
state=WAITING, group=TGRP-ChaosMonkeySafeLeaderWithPullReplicasTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at 
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at 
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2>   22) Thread[id=12919, name=Scheduler-457900546, 
state=WAITING, group=TGRP-ChaosMonkeySafeLeaderWithPullReplicasTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at 
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
   [junit4]   2>         at 
java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>         at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2>   23) Thread[id=13057, name=qtp326633058-13057, 
state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderWithPullReplicasTest]
   [junit4]   2>         at sun.nio.ch.KQueueArrayWrapper.interrupt(Native 
Method)
   [junit4]   2>         at 
sun.nio.ch.KQueueArrayWrapper.interrupt(KQueueArrayWrapper.java:203)
   [junit4]   2>         at 
sun.nio.ch.KQueueSelectorImpl.wakeup(KQueueSelectorImpl.java:257)
   [junit4]   2>         at 
java.nio.channels.spi.AbstractSelector$1.interrupt(AbstractSelector.java:213)
   [junit4]   2>         at 
java.nio.channels.spi.AbstractSelector.begin(AbstractSelector.java:219)
   [junit4]   2>         at 
sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:116)
   [junit4]   2>         at 
sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
   [junit4]   2>         at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
   [junit4]   2>         at 
sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
   [junit4]   2>         at 
org.eclipse.jetty.io.ManagedSelector$SelectorProducer.select(ManagedSelector.java:243)
   [junit4]   2>         at 
org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:191)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:249)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> NOTE: test params are: codec=Lucene70, 
sim=RandomSimilarity(queryNorm=true): {}, locale=it-IT, timezone=Etc/GMT-2
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_131 
(64-bit)/cpus=3,threads=54,free=311306320,total=485859328
   [junit4]   2> NOTE: All tests run in this JVM: [SynonymTokenizerTest, 
TriLevelCompositeIdRoutingTest, OutOfBoxZkACLAndCredentialsProvidersTest, 
HdfsCollectionsAPIDistributedZkTest, QueryElevationComponentTest, 
ConfigureRecoveryStrategyTest, BlockJoinFacetRandomTest, TestTrieFacet, 
TestPartialUpdateDeduplication, TestSolrCoreSnapshots, ZkStateReaderTest, 
ClusterStateUpdateTest, HdfsBasicDistributedZk2Test, TestSystemIdResolver, 
TestCloudJSONFacetJoinDomain, AtomicUpdatesTest, DocValuesMissingTest, 
DocValuesTest, TestSolrCLIRunExample, TestUpdate, BJQParserTest, 
SimpleFacetsTest, SpatialRPTFieldTypeTest, TestCSVResponseWriter, 
CdcrVersionReplicationTest, DistributedFacetPivotLargeTest, 
TestSolrCloudWithDelegationTokens, ShardRoutingTest, TestBlobHandler, 
TestShortCircuitedRequests, TestCollationField, 
TestTolerantUpdateProcessorRandomCloud, AutoScalingHandlerTest, 
SubstringBytesRefFilterTest, PolyFieldTest, RequiredFieldsTest, 
TestStressReorder, TestSweetSpotSimilarityFactory, TestLFUCache, 
SolrCLIZkUtilsTest, SharedFSAutoReplicaFailoverUtilsTest, DateFieldTest, 
TolerantUpdateProcessorTest, UnloadDistributedZkTest, DirectUpdateHandlerTest, 
SolrPluginUtilsTest, ResourceLoaderTest, TestManagedSchemaAPI, 
TestStressVersions, UtilsToolTest, TestSearcherReuse, 
SpellingQueryConverterTest, TestStressInPlaceUpdates, MultiTermTest, 
JavabinLoaderTest, RecoveryAfterSoftCommitTest, RecoveryZkTest, 
TestTolerantSearch, DeleteNodeTest, TestSort, 
TestSolrCloudWithSecureImpersonation, BasicDistributedZkTest, TestRTGBase, 
TestConfigSetsAPI, MetricUtilsTest, TestImplicitCoreProperties, 
TestCustomStream, TestSmileRequest, CurrencyFieldXmlFileTest, 
ConnectionReuseTest, HdfsChaosMonkeyNothingIsSafeTest, 
TestDynamicFieldResource, TestDistribIDF, 
BigEndianAscendingWordDeserializerTest, HdfsRestartWhileUpdatingTest, 
LeaderFailureAfterFreshStartTest, CloneFieldUpdateProcessorFactoryTest, 
TestTlogReplica, CleanupOldIndexTest, TestUseDocValuesAsStored2, 
CoreAdminCreateDiscoverTest, StatelessScriptUpdateProcessorFactoryTest, 
BasicAuthIntegrationTest, DeleteShardTest, TestMissingGroups, 
CollectionsAPISolrJTest, TestNumericRangeQuery32, TestCoreAdminApis, 
HdfsRecoverLeaseTest, TestSolrCoreParser, ShardSplitTest, TestMacros, 
TestSimpleTextCodec, TestLeaderElectionZkExpiry, TestConfigSets, 
SuggesterFSTTest, BlockDirectoryTest, TestImpersonationWithHadoopAuth, 
TestCustomDocTransformer, SolrCloudReportersTest, TestConfigSetsAPIZkFailure, 
TestCloudPseudoReturnFields, LeaderElectionTest, DistributedMLTComponentTest, 
CdcrBootstrapTest, DataDrivenBlockJoinTest, TestStandardQParsers, 
StandardRequestHandlerTest, TestRebalanceLeaders, 
ClassificationUpdateProcessorIntegrationTest, TestLocalFSCloudBackupRestore, 
ChangedSchemaMergeTest, ZkControllerTest, TestPerFieldSimilarity, 
LeaderElectionContextKeyTest, SmileWriterTest, DocumentBuilderTest, 
SoftAutoCommitTest, SpatialFilterTest, TestJavabinTupleStreamParser, 
TestSha256AuthenticationProvider, TestReqParamsAPI, 
LeaderInitiatedRecoveryOnShardRestartTest, TestStressLucene, 
HdfsUnloadDistributedZkTest, TestSchemaVersionResource, QueryEqualityTest, 
MultiThreadedOCPTest, SolrJmxReporterTest, 
ChaosMonkeySafeLeaderWithPullReplicasTest]
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=ChaosMonkeySafeLeaderWithPullReplicasTest 
-Dtests.seed=4D6AF2FB59880323 -Dtests.slow=true -Dtests.locale=it-IT 
-Dtests.timezone=Etc/GMT-2 -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | ChaosMonkeySafeLeaderWithPullReplicasTest 
(suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 
7200000 msec).
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([4D6AF2FB59880323]:0)
   [junit4] Completed [674/724 (3!)] on J0 in 7224.54s, 1 test, 2 errors <<< 
FAILURES!

[...truncated 43559 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to