Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.x/584/

1 tests failed.
FAILED:  org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.test_dv

Error Message:
There are still nodes recoverying - waited for 330 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 
seconds
        at 
__randomizedtesting.SeedInfo.seed([85025F84010A9786:B3163DC28B57AD97]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at 
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:184)
        at 
org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.waitForRecoveriesToFinish(TestStressCloudBlindAtomicUpdates.java:459)
        at 
org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.checkField(TestStressCloudBlindAtomicUpdates.java:304)
        at 
org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.test_dv(TestStressCloudBlindAtomicUpdates.java:193)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
        at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 12670 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/init-core-data-001
   [junit4]   2> 1850928 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=SSL overhead seems to cause 
OutOfMemory when stress testing)
   [junit4]   2> 1850928 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001
   [junit4]   2> 1850929 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1850929 INFO  (Thread-3974) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1850929 INFO  (Thread-3974) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1851029 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:39576
   [junit4]   2> 1851037 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1851040 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1851041 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1851041 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1851043 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@5cfbfd89{/solr,null,AVAILABLE}
   [junit4]   2> 1851043 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@5e12ff77{HTTP/1.1,[http/1.1]}{127.0.0.1:43054}
   [junit4]   2> 1851043 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.e.j.s.Server Started @1855471ms
   [junit4]   2> 1851044 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=43054}
   [junit4]   2> 1851044 ERROR (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1851044 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
6.4.0
   [junit4]   2> 1851044 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1851044 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1851044 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-12-05T23:07:51.470Z
   [junit4]   2> 1851046 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@48bfa84{/solr,null,AVAILABLE}
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@2688dc92{HTTP/1.1,[http/1.1]}{127.0.0.1:46978}
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.e.j.s.Server Started @1855474ms
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=46978}
   [junit4]   2> 1851047 ERROR (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
6.4.0
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1851047 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-12-05T23:07:51.473Z
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@60deae04{/solr,null,AVAILABLE}
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@e98e57e{HTTP/1.1,[http/1.1]}{127.0.0.1:50560}
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.e.j.s.Server Started @1855477ms
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=50560}
   [junit4]   2> 1851050 ERROR (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
6.4.0
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1851050 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-12-05T23:07:51.476Z
   [junit4]   2> 1851053 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@5f9a70cf{/solr,null,AVAILABLE}
   [junit4]   2> 1851053 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@5e1a298{HTTP/1.1,[http/1.1]}{127.0.0.1:34881}
   [junit4]   2> 1851053 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.e.j.s.Server Started @1855481ms
   [junit4]   2> 1851054 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=34881}
   [junit4]   2> 1851054 ERROR (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1851054 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
6.4.0
   [junit4]   2> 1851054 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1851054 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1851054 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-12-05T23:07:51.480Z
   [junit4]   2> 1851056 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1851062 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1851079 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1851107 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1851109 INFO  (jetty-launcher-2322-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39576/solr
   [junit4]   2> 1851110 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1851120 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1851121 INFO  (jetty-launcher-2322-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39576/solr
   [junit4]   2> 1851121 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1851136 INFO  (jetty-launcher-2322-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39576/solr
   [junit4]   2> 1851145 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1851146 INFO  (jetty-launcher-2322-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:39576/solr
   [junit4]   2> 1851156 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x158d13e4ebc0007, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 1851171 INFO  (jetty-launcher-2322-thread-1) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:46978_solr
   [junit4]   2> 1851172 INFO  (jetty-launcher-2322-thread-1) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.Overseer Overseer 
(id=97057457527586824-127.0.0.1:46978_solr-n_0000000000) starting
   [junit4]   2> 1851177 INFO  (jetty-launcher-2322-thread-2) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:43054_solr
   [junit4]   2> 1851187 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1851192 INFO  (jetty-launcher-2322-thread-3) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:34881_solr
   [junit4]   2> 1851194 INFO  (jetty-launcher-2322-thread-4) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1851194 INFO  
(zkCallback-2343-thread-1-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1851194 INFO  
(zkCallback-2341-thread-1-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1851194 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1851197 INFO  (jetty-launcher-2322-thread-4) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:50560_solr
   [junit4]   2> 1851199 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1851213 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (3)
   [junit4]   2> 1851213 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1851222 INFO  (jetty-launcher-2322-thread-1) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:46978_solr
   [junit4]   2> 1851224 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1851225 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1851232 INFO  (jetty-launcher-2322-thread-4) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node4/.
   [junit4]   2> 1851232 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1851233 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (4)
   [junit4]   2> 1851262 INFO  (jetty-launcher-2322-thread-2) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node2/.
   [junit4]   2> 1851315 INFO  (jetty-launcher-2322-thread-1) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node1/.
   [junit4]   2> 1851333 INFO  (jetty-launcher-2322-thread-3) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node3/.
   [junit4]   2> 1851346 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1851348 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39576/solr ready
   [junit4]   2> 1851796 INFO  (qtp872843883-14410) [n:127.0.0.1:34881_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&name=test_col&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1851805 INFO  
(OverseerThreadFactory-6751-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
test_col
   [junit4]   2> 1851930 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard2_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2
   [junit4]   2> 1851935 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard2_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2
   [junit4]   2> 1851948 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard1_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1851949 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard1_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1852060 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1852060 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1852060 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1852061 INFO  
(zkCallback-2337-thread-3-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1852960 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2  x:test_col_shard2_replica1] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 6.4.0
   [junit4]   2> 1852969 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1  x:test_col_shard1_replica1] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 6.4.0
   [junit4]   2> 1852972 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2  x:test_col_shard2_replica1] o.a.s.s.IndexSchema 
[test_col_shard2_replica1] Schema name=minimal-atomic-stress
   [junit4]   2> 1852975 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2  x:test_col_shard2_replica1] o.a.s.s.IndexSchema Loaded 
schema minimal-atomic-stress/1.6 with uniqueid field id
   [junit4]   2> 1852976 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2  x:test_col_shard2_replica1] o.a.s.c.CoreContainer Creating 
SolrCore 'test_col_shard2_replica1' using configuration from collection test_col
   [junit4]   2> 1852976 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] o.a.s.c.SolrCore 
[[test_col_shard2_replica1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node4/test_col_shard2_replica1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node4/./test_col_shard2_replica1/data/]
   [junit4]   2> 1852977 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61fc2c21
   [junit4]   2> 1852978 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=50, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=84.3916015625, 
floorSegmentMB=0.55859375, forceMergeDeletesPctAllowed=0.20081189050133674, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1852978 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2  x:test_col_shard2_replica2] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 6.4.0
   [junit4]   2> 1852983 WARN  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 1852996 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1  x:test_col_shard1_replica2] o.a.s.c.SolrConfig Using 
Lucene MatchVersion: 6.4.0
   [junit4]   2> 1853007 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2  x:test_col_shard2_replica2] o.a.s.s.IndexSchema 
[test_col_shard2_replica2] Schema name=minimal-atomic-stress
   [junit4]   2> 1853009 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2  x:test_col_shard2_replica2] o.a.s.s.IndexSchema Loaded 
schema minimal-atomic-stress/1.6 with uniqueid field id
   [junit4]   2> 1853012 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2  x:test_col_shard2_replica2] o.a.s.c.CoreContainer Creating 
SolrCore 'test_col_shard2_replica2' using configuration from collection test_col
   [junit4]   2> 1853012 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] o.a.s.c.SolrCore 
[[test_col_shard2_replica2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node3/test_col_shard2_replica2],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node3/./test_col_shard2_replica2/data/]
   [junit4]   2> 1853012 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61fc2c21
   [junit4]   2> 1853014 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=50, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=84.3916015625, 
floorSegmentMB=0.55859375, forceMergeDeletesPctAllowed=0.20081189050133674, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1853015 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1  x:test_col_shard1_replica1] o.a.s.s.IndexSchema 
[test_col_shard1_replica1] Schema name=minimal-atomic-stress
   [junit4]   2> 1853018 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1  x:test_col_shard1_replica1] o.a.s.s.IndexSchema Loaded 
schema minimal-atomic-stress/1.6 with uniqueid field id
   [junit4]   2> 1853019 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1  x:test_col_shard1_replica2] o.a.s.s.IndexSchema 
[test_col_shard1_replica2] Schema name=minimal-atomic-stress
   [junit4]   2> 1853020 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1853020 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1853021 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1853021 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1853021 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1  x:test_col_shard1_replica2] o.a.s.s.IndexSchema Loaded 
schema minimal-atomic-stress/1.6 with uniqueid field id
   [junit4]   2> 1853021 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=3.4052734375, 
floorSegmentMB=2.095703125, forceMergeDeletesPctAllowed=21.764501697383835, 
segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1853022 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@533a9e3[test_col_shard2_replica1] 
main]
   [junit4]   2> 1853022 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1  x:test_col_shard1_replica2] o.a.s.c.CoreContainer Creating 
SolrCore 'test_col_shard1_replica2' using configuration from collection test_col
   [junit4]   2> 1853023 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853024 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1  x:test_col_shard1_replica1] o.a.s.c.CoreContainer Creating 
SolrCore 'test_col_shard1_replica1' using configuration from collection test_col
   [junit4]   2> 1853024 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853024 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] o.a.s.c.SolrCore 
[[test_col_shard1_replica2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node2/test_col_shard1_replica2],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node2/./test_col_shard1_replica2/data/]
   [junit4]   2> 1853024 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1853024 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61fc2c21
   [junit4]   2> 1853025 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.c.SolrCore 
[[test_col_shard1_replica1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node1/test_col_shard1_replica1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001/tempDir-001/node1/./test_col_shard1_replica1/data/]
   [junit4]   2> 1853025 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61fc2c21
   [junit4]   2> 1853025 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1552919322638155776
   [junit4]   2> 1853027 INFO  
(searcherExecutor-6760-thread-1-processing-n:127.0.0.1:50560_solr 
x:test_col_shard2_replica1 s:shard2 c:test_col r:core_node2) 
[n:127.0.0.1:50560_solr c:test_col s:shard2 r:core_node2 
x:test_col_shard2_replica1] o.a.s.c.SolrCore [test_col_shard2_replica1] 
Registered new searcher Searcher@533a9e3[test_col_shard2_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1853033 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=50, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=84.3916015625, 
floorSegmentMB=0.55859375, forceMergeDeletesPctAllowed=0.20081189050133674, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1853037 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=50, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=84.3916015625, 
floorSegmentMB=0.55859375, forceMergeDeletesPctAllowed=0.20081189050133674, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1853038 WARN  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 1853045 WARN  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 1853050 WARN  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 1853055 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard2: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 1853058 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1853058 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1853059 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1853059 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1853059 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=3.4052734375, 
floorSegmentMB=2.095703125, forceMergeDeletesPctAllowed=21.764501697383835, 
segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1853060 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1afd818c[test_col_shard1_replica1] 
main]
   [junit4]   2> 1853061 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1853061 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1853061 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853062 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853062 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1853062 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1853062 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1853062 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1552919322676953088
   [junit4]   2> 1853062 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=3.4052734375, 
floorSegmentMB=2.095703125, forceMergeDeletesPctAllowed=21.764501697383835, 
segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1853062 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@303b91df[test_col_shard1_replica2] 
main]
   [junit4]   2> 1853063 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1853063 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1853064 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1853064 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1853065 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=3.4052734375, 
floorSegmentMB=2.095703125, forceMergeDeletesPctAllowed=21.764501697383835, 
segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1853065 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853065 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3b1c8697[test_col_shard2_replica2] 
main]
   [junit4]   2> 1853066 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853066 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1853066 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1552919322681147392
   [junit4]   2> 1853069 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853069 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2> 1853069 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1853070 INFO  
(searcherExecutor-6766-thread-1-processing-n:127.0.0.1:43054_solr 
x:test_col_shard1_replica2 s:shard1 c:test_col r:core_node3) 
[n:127.0.0.1:43054_solr c:test_col s:shard1 r:core_node3 
x:test_col_shard1_replica2] o.a.s.c.SolrCore [test_col_shard1_replica2] 
Registered new searcher Searcher@303b91df[test_col_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1853070 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1552919322685341696
   [junit4]   2> 1853073 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1853073 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1853073 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:46978/solr/test_col_shard1_replica1/
   [junit4]   2> 1853073 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.u.PeerSync 
PeerSync: core=test_col_shard1_replica1 url=http://127.0.0.1:46978/solr START 
replicas=[http://127.0.0.1:43054/solr/test_col_shard1_replica2/] nUpdates=100
   [junit4]   2> 1853074 INFO  
(searcherExecutor-6762-thread-1-processing-n:127.0.0.1:34881_solr 
x:test_col_shard2_replica2 s:shard2 c:test_col r:core_node1) 
[n:127.0.0.1:34881_solr c:test_col s:shard2 r:core_node1 
x:test_col_shard2_replica2] o.a.s.c.SolrCore [test_col_shard2_replica2] 
Registered new searcher Searcher@3b1c8697[test_col_shard2_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1853075 INFO  
(searcherExecutor-6767-thread-1-processing-n:127.0.0.1:46978_solr 
x:test_col_shard1_replica1 s:shard1 c:test_col r:core_node4) 
[n:127.0.0.1:46978_solr c:test_col s:shard1 r:core_node4 
x:test_col_shard1_replica1] o.a.s.c.SolrCore [test_col_shard1_replica1] 
Registered new searcher Searcher@1afd818c[test_col_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1853075 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.u.PeerSync 
PeerSync: core=test_col_shard1_replica1 url=http://127.0.0.1:46978/solr DONE.  
We have no versions.  sync failed.
   [junit4]   2> 1853082 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] o.a.s.c.S.Request 
[test_col_shard1_replica2]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1853082 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 1853082 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 1853089 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:46978/solr/test_col_shard1_replica1/ shard1
   [junit4]   2> 1853192 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853193 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853194 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853194 INFO  
(zkCallback-2337-thread-2-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853242 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1853244 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard1_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2}
 status=0 QTime=1295
   [junit4]   2> 1853347 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853347 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853347 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853348 INFO  
(zkCallback-2337-thread-3-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853556 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1853556 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1853556 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:50560/solr/test_col_shard2_replica1/
   [junit4]   2> 1853556 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] o.a.s.u.PeerSync 
PeerSync: core=test_col_shard2_replica1 url=http://127.0.0.1:50560/solr START 
replicas=[http://127.0.0.1:34881/solr/test_col_shard2_replica2/] nUpdates=100
   [junit4]   2> 1853557 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] o.a.s.u.PeerSync 
PeerSync: core=test_col_shard2_replica1 url=http://127.0.0.1:50560/solr DONE.  
We have no versions.  sync failed.
   [junit4]   2> 1853559 INFO  (qtp872843883-14412) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] o.a.s.c.S.Request 
[test_col_shard2_replica2]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1853559 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 1853559 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 1853562 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:50560/solr/test_col_shard2_replica1/ shard2
   [junit4]   2> 1853666 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853666 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853666 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853666 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853714 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1853716 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard2_replica1&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2}
 status=0 QTime=1781
   [junit4]   2> 1853818 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853818 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853818 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1853818 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1854073 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard1_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard1&wt=javabin&version=2}
 status=0 QTime=2125
   [junit4]   2> 1854077 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&name=test_col_shard2_replica2&action=CREATE&numShards=2&collection=test_col&shard=shard2&wt=javabin&version=2}
 status=0 QTime=2146
   [junit4]   2> 1854084 INFO  (qtp872843883-14410) [n:127.0.0.1:34881_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> 1854179 INFO  
(zkCallback-2341-thread-2-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1854179 INFO  
(zkCallback-2337-thread-1-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1854179 INFO  
(zkCallback-2344-thread-1-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1854179 INFO  
(zkCallback-2343-thread-2-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [4])
   [junit4]   2> 1855084 INFO  (qtp872843883-14410) [n:127.0.0.1:34881_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&property.config=solrconfig-tlog.xml&property.schema=schema-minimal-atomic-stress.xml&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&name=test_col&action=CREATE&numShards=2&wt=javabin&version=2}
 status=0 QTime=3288
   [junit4]   2> 1855084 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: 
test_col failOnTimeout:true timeout (sec):330
   [junit4]   1> -
   [junit4]   1> replica:core_node3 rstate:active live:true
   [junit4]   1> replica:core_node4 rstate:active live:true
   [junit4]   1> replica:core_node1 rstate:active live:true
   [junit4]   1> replica:core_node2 rstate:active live:true
   [junit4]   1> no one is recoverying
   [junit4]   2> 1855085 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: test_col
   [junit4]   2> 1855091 INFO  (qtp1157631983-14385) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] o.a.s.c.S.Request 
[test_col_shard1_replica1]  webapp=/solr path=/schema/fieldtypes/long 
params={wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 1855125 INFO  
(TEST-TestStressCloudBlindAtomicUpdates.test_dv_stored_idx-seed#[85025F84010A9786])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting test_dv_stored_idx
   [junit4]   2> 1855145 INFO  (qtp872843883-14412) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&_version_=-1552919324845408256&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
 (-1552919324845408256)} 0 10
   [junit4]   2> 1855147 INFO  (qtp1976253561-14378) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&_version_=-1552919324847505408&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
 (-1552919324847505408)} 0 1
   [junit4]   2> 1855147 INFO  (qtp1157631983-14390) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update 
params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{deleteByQuery=*:*
 (-1552919324847505408)} 0 14
   [junit4]   2> 1855147 INFO  (qtp1407036255-14397) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{deleteByQuery=*:* 
(-1552919324845408256)} 0 17
   [junit4]   2> 1855150 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1855150 WARN  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the 
entire index! Use with care.
   [junit4]   2> 1855151 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1855151 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1855151 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=}
 0 1
   [junit4]   2> 1855151 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1855151 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1855151 WARN  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the 
entire index! Use with care.
   [junit4]   2> 1855152 WARN  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the 
entire index! Use with care.
   [junit4]   2> 1855152 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1855153 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1855153 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1855153 WARN  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the 
entire index! Use with care.
   [junit4]   2> 1855153 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=}
 0 2
   [junit4]   2> 1855153 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1855154 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 1855155 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1855155 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1855155 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=}
 0 3
   [junit4]   2> 1855155 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=}
 0 2
   [junit4]   2> 1855158 INFO  (qtp1407036255-14401) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update 
params={_stateVer_=test_col:6&optimize=true&maxSegments=1&waitSearcher=true&wt=javabin&version=2}{optimize=}
 0 9
   [junit4]   2> 1855159 INFO  (qtp1976253561-14373) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] o.a.s.c.S.Request 
[test_col_shard1_replica2]  webapp=/solr path=/schema/fields/long_dv_stored_idx 
params={wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 1855160 INFO  
(TEST-TestStressCloudBlindAtomicUpdates.test_dv_stored_idx-seed#[85025F84010A9786])
 [    ] o.a.s.c.TestStressCloudBlindAtomicUpdates Testing long_dv_stored_idx: 
numDocsToCheck=111, numDocsInIndex=666, incr=6
   [junit4]   2> 1855166 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[0
 (1552919324880011264)]} 0 0
   [junit4]   2> 1855166 INFO  (qtp1157631983-14384) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[0 (1552919324880011264)]} 0 3
   [junit4]   2> 1855170 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[1
 (1552919324885254144)]} 0 0
   [junit4]   2> 1855170 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[1 (1552919324885254144)]} 0 1
   [junit4]   2> 1855175 INFO  (qtp872843883-14413) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[2
 (1552919324888399872)]} 0 0
   [junit4]   2> 1855175 INFO  (qtp1407036255-14396) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[2 (1552919324888399872)]} 0 3
   [junit4]   2> 1855178 INFO  (qtp872843883-14414) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[3
 (1552919324894691328)]} 0 0
   [junit4]   2> 1855179 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[3 (1552919324894691328)]} 0 2
   [junit4]   2> 1855182 INFO  (qtp1976253561-14378) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[4
 (1552919324897837056)]} 0 0
   [junit4]   2> 1855182 INFO  (qtp1157631983-14389) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[4 (1552919324897837056)]} 0 2
   [junit4]   2> 1855186 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[5
 (1552919324902031360)]} 0 0
   [junit4]   2> 1855186 INFO  (qtp1407036255-14397) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[5 (1552919324902031360)]} 0 2
   [junit4]   2> 1855189 INFO  (qtp872843883-14410) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[6
 (1552919324906225664)]} 0 0
   [junit4]   2> 1855190 INFO  (qtp1407036255-14403) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[6 (1552919324906225664)]} 0 2
   [junit4]   2> 1855193 INFO  (qtp872843883-14412) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[7
 (1552919324909371392)]} 0 0
   [junit4]   2> 1855193 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[7 (1552919324909371392)]} 0 1
   [junit4]   2> 1855197 INFO  (qtp1976253561-14378) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[8
 (1552919324913565696)]} 0 0
   [junit4]   2> 1855197 INFO  (qtp1157631983-14385) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[8 (1552919324913565696)]} 0 1
   [junit4]   2> 1855200 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[9
 (1552919324916711424)]} 0 0
   [junit4]   2> 1855200 INFO  (qtp1407036255-14401) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[9 (1552919324916711424)]} 0 1
   [junit4]   2> 1855204 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[10
 (1552919324920905728)]} 0 0
   [junit4]   2> 1855204 INFO  (qtp1157631983-14390) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[10 (1552919324920905728)]} 0 1
   [junit4]   2> 1855207 INFO  (qtp1976253561-14373) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[11
 (1552919324925100032)]} 0 0
   [junit4]   2> 1855208 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[11 (1552919324925100032)]} 0 2
   [junit4]   2> 1855211 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[12
 (1552919324928245760)]} 0 0
   [junit4]   2> 1855211 INFO  (qtp1157631983-14384) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[12 (1552919324928245760)]} 0 2
   [junit4]   2> 1855215 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[13
 (1552919324932440064)]} 0 0
   [junit4]   2> 1855215 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[13 (1552919324932440064)]} 0 2
   [junit4]   2> 1855218 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[14
 (1552919324936634368)]} 0 0
   [junit4]   2> 1855218 INFO  (qtp1157631983-14389) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[14 (1552919324936634368)]} 0 1
   [junit4]   2> 1855222 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[15
 (1552919324939780096)]} 0 0
   [junit4]   2> 1855222 INFO  (qtp1157631983-14385) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[15 (1552919324939780096)]} 0 2
   [junit4]   2> 1855225 INFO  (qtp1976253561-14379) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[16
 (1552919324943974400)]} 0 0
   [junit4]   2> 1855226 INFO  (qtp1157631983-14390) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[16 (1552919324943974400)]} 0 1
   [junit4]   2> 1855229 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[17
 (1552919324947120128)]} 0 0
   [junit4]   2> 1855229 INFO  (qtp1407036255-14396) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[17 (1552919324947120128)]} 0 2
   [junit4]   2> 1855233 INFO  (qtp872843883-14414) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[18
 (1552919324951314432)]} 0 0
   [junit4]   2> 1855233 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[18 (1552919324951314432)]} 0 1
   [junit4]   2> 1855236 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[19
 (1552919324955508736)]} 0 0
   [junit4]   2> 1855237 INFO  (qtp1407036255-14397) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[19 (1552919324955508736)]} 0 2
   [junit4]   2> 1855240 INFO  (qtp1976253561-14373) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[20
 (1552919324958654464)]} 0 0
   [junit4]   2> 1855240 INFO  (qtp1157631983-14391) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[20 (1552919324958654464)]} 0 2
   [junit4]   2> 1855244 INFO  (qtp872843883-14410) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[21
 (1552919324962848768)]} 0 0
   [junit4]   2> 1855244 INFO  (qtp1407036255-14403) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[21 (1552919324962848768)]} 0 2
   [junit4]   2> 1855248 INFO  (qtp1976253561-14375) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[22
 (1552919324967043072)]} 0 0
   [junit4]   2> 1855248 INFO  (qtp1157631983-14384) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[22 (1552919324967043072)]} 0 2
   [junit4]   2> 1855251 INFO  (qtp872843883-14412) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[23
 (1552919324971237376)]} 0 0
   [junit4]   2> 1855251 INFO  (qtp1407036255-14402) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[23 (1552919324971237376)]} 0 2
   [junit4]   2> 1855255 INFO  (qtp1976253561-14371) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[24
 (1552919324974383104)]} 0 0
   [junit4]   2> 1855256 INFO  (qtp1157631983-14387) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[24 (1552919324974383104)]} 0 2
   [junit4]   2> 1855259 INFO  (qtp872843883-14413) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[25
 (1552919324978577408)]} 0 0
   [junit4]   2> 1855259 INFO  (qtp1407036255-14401) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[25 (1552919324978577408)]} 0 2
   [junit4]   2> 1855263 INFO  (qtp872843883-14372) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[26
 (1552919324982771712)]} 0 0
   [junit4]   2> 1855263 INFO  (qtp1407036255-14396) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[26 (1552919324982771712)]} 0 2
   [junit4]   2> 1855266 INFO  (qtp1976253561-14371) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[27
 (1552919324986966016)]} 0 0
   [junit4]   2> 1855267 INFO  (qtp1157631983-14389) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[27 (1552919324986966016)]} 0 1
   [junit4]   2> 1855270 INFO  (qtp1976253561-14377) [n:127.0.0.1:43054_solr 
c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46978/solr/test_col_shard1_replica1/&wt=javabin&version=2}{add=[28
 (1552919324990111744)]} 0 0
   [junit4]   2> 1855270 INFO  (qtp1157631983-14385) [n:127.0.0.1:46978_solr 
c:test_col s:shard1 r:core_node4 x:test_col_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[28 (1552919324990111744)]} 0 1
   [junit4]   2> 1855274 INFO  (qtp872843883-14414) [n:127.0.0.1:34881_solr 
c:test_col s:shard2 r:core_node1 x:test_col_shard2_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica2]  webapp=/solr 
path=/update 
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:50560/solr/test_col_shard2_replica1/&wt=javabin&version=2}{add=[29
 (1552919324994306048)]} 0 0
   [junit4]   2> 1855274 INFO  (qtp1407036255-14399) [n:127.0.0.1:50560_solr 
c:test_col s:shard2 r:core_node2 x:test_col_shard2_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica1]  webapp=/solr 
path=/update params={wt=javabin&version=2}{add=[29 (1552919324994306048)]} 0 1
   [junit4]   2> 1855277 INFO  (qtp872843883-14408) [n:127.0.0.1:34881_s

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

nged path:/collections/test_col/state.json] for collection [test_col] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2231967 INFO  
(zkCallback-2343-thread-3-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [3])
   [junit4]   2> 2231977 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x158d13e4ebc000b, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 2231978 INFO  
(zkCallback-2341-thread-3-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (1)
   [junit4]   2> 2231978 INFO  
(zkCallback-2341-thread-4-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [1])
   [junit4]   2> 2231979 INFO  
(zkCallback-2341-thread-3-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/test_col/state.json] for collection [test_col] has occurred - 
updating... (live nodes size: [1])
   [junit4]   2> 2231992 INFO  (jetty-launcher-2322-thread-6) [    ] 
o.a.s.c.Overseer Overseer 
(id=97057457527586826-127.0.0.1:43054_solr-n_0000000001) closing
   [junit4]   2> 2231992 INFO  
(OverseerStateUpdate-97057457527586826-127.0.0.1:43054_solr-n_0000000001) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:43054_solr
   [junit4]   2> 2233430 WARN  
(zkCallback-2337-thread-6-processing-n:127.0.0.1:46978_solr) 
[n:127.0.0.1:46978_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 2233430 INFO  (jetty-launcher-2322-thread-7) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@48bfa84{/solr,null,UNAVAILABLE}
   [junit4]   2> 2233477 WARN  
(zkCallback-2343-thread-3-processing-n:127.0.0.1:34881_solr) 
[n:127.0.0.1:34881_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 2233477 INFO  (jetty-launcher-2322-thread-8) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@5f9a70cf{/solr,null,UNAVAILABLE}
   [junit4]   2> 2233477 WARN  
(zkCallback-2344-thread-2-processing-n:127.0.0.1:50560_solr) 
[n:127.0.0.1:50560_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 2233478 INFO  (jetty-launcher-2322-thread-5) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@60deae04{/solr,null,UNAVAILABLE}
   [junit4]   2> 2233494 WARN  
(zkCallback-2341-thread-4-processing-n:127.0.0.1:43054_solr) 
[n:127.0.0.1:43054_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 2233494 INFO  (jetty-launcher-2322-thread-6) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@5cfbfd89{/solr,null,UNAVAILABLE}
   [junit4]   2> 2233496 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:39576 39576
   [junit4]   2> 2233582 INFO  (Thread-3974) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:39576 39576
   [junit4]   2> 2233583 WARN  (Thread-3974) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        5       /solr/aliases.json
   [junit4]   2>        5       /solr/clusterprops.json
   [junit4]   2>        4       
/solr/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
   [junit4]   2>        4       /solr/security.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        5       /solr/clusterstate.json
   [junit4]   2>        4       /solr/collections/test_col/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        378     /solr/overseer/collection-queue-work
   [junit4]   2>        29      /solr/overseer/queue
   [junit4]   2>        6       /solr/overseer/queue-work
   [junit4]   2>        5       /solr/live_nodes
   [junit4]   2>        5       /solr/collections
   [junit4]   2> 
   [junit4]   2> 2233583 INFO  
(SUITE-TestStressCloudBlindAtomicUpdates-seed#[85025F84010A9786]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_85025F84010A9786-001
   [junit4]   2> NOTE: test params are: 
codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION,
 chunkSize=3, maxDocsPerChunk=2, blockSize=523), 
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION,
 chunkSize=3, blockSize=523)), 
sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=ar, 
timezone=Pacific/Guam
   [junit4]   2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 
1.8.0_102 (64-bit)/cpus=4,threads=1,free=218552080,total=526909440
   [junit4]   2> NOTE: All tests run in this JVM: [HdfsRecoveryZkTest, 
SmileWriterTest, TestTrieFacet, ForceLeaderTest, RuleEngineTest, TestOrdValues, 
ResponseHeaderTest, DocExpirationUpdateProcessorFactoryTest, 
PrimitiveFieldTypeTest, BinaryUpdateRequestHandlerTest, DistributedQueueTest, 
SolrTestCaseJ4Test, TestFieldCacheVsDocValues, 
TestLMJelinekMercerSimilarityFactory, SpellPossibilityIteratorTest, 
LeaderFailoverAfterPartitionTest, QueryParsingTest, HardAutoCommitTest, 
OverseerTest, DataDrivenBlockJoinTest, SuggesterTSTTest, 
LukeRequestHandlerTest, TestAddFieldRealTimeGet, SuggesterTest, 
CircularListTest, AddSchemaFieldsUpdateProcessorFactoryTest, 
CoreMergeIndexesAdminHandlerTest, TestConfigSetImmutable, GraphQueryTest, 
TestMergePolicyConfig, TestSimpleQParserPlugin, TestDefaultSearchFieldResource, 
RemoteQueryErrorTest, HdfsCollectionsAPIDistributedZkTest, TestWriterPerf, 
TestDocTermOrds, TestHdfsCloudBackupRestore, TestJsonFacetRefinement, 
TestMiniSolrCloudCluster, TestPivotHelperCode, OverseerModifyCollectionTest, 
SparseHLLTest, TestInitQParser, TestCloudPseudoReturnFields, 
TestSolrFieldCacheMBean, CdcrBootstrapTest, TestCorePropertiesReload, 
CollectionsAPISolrJTest, TestRuleBasedAuthorizationPlugin, 
SegmentsInfoRequestHandlerTest, TestSolrQueryParser, 
ShowFileRequestHandlerTest, RequestHandlersTest, HdfsBasicDistributedZkTest, 
TestRebalanceLeaders, TestObjectReleaseTracker, CoreAdminHandlerTest, 
TestCollationField, TolerantUpdateProcessorTest, BasicDistributedZk2Test, 
TestFieldTypeResource, TestHighFrequencyDictionaryFactory, 
TestJavabinTupleStreamParser, BadIndexSchemaTest, 
DistributedExpandComponentTest, TestSchemaSimilarityResource, 
TestDFRSimilarityFactory, NoCacheHeaderTest, DeleteInactiveReplicaTest, 
HdfsThreadLeakTest, DistributedSuggestComponentTest, LeaderElectionTest, 
BooleanFieldTest, TestManagedResource, AssignTest, TestTestInjection, 
TestPostingsSolrHighlighter, TestCloudDeleteByQuery, TestExceedMaxTermLength, 
TestImplicitCoreProperties, PrimUtilsTest, AnalyticsMergeStrategyTest, 
TestClassicSimilarityFactory, TestUtils, DistributedFacetPivotLongTailTest, 
TestNoOpRegenerator, TestIndexSearcher, TestLeaderInitiatedRecoveryThread, 
SuggestComponentTest, PreAnalyzedFieldTest, TimeZoneUtilsTest, 
SaslZkACLProviderTest, TestManagedSchema, 
ClassificationUpdateProcessorIntegrationTest, TestReload, 
HdfsWriteToMultipleCollectionsTest, CollectionStateFormat2Test, 
TestSchemaManager, RecoveryZkTest, DirectoryFactoryTest, 
OpenExchangeRatesOrgProviderTest, TestDefaultStatsCache, FullHLLTest, 
RestartWhileUpdatingTest, MinimalSchemaTest, DirectUpdateHandlerTest, 
ClusterStateUpdateTest, AutoCommitTest, TestRecovery, 
TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, 
DistributedTermsComponentTest, TestCoreContainer, SimpleFacetsTest, 
SolrCoreTest, TestGroupingSearch, QueryElevationComponentTest, TestSort, 
TestBadConfig, SoftAutoCommitTest, SuggesterWFSTTest, 
SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, 
DirectUpdateHandlerOptimizeTest, DocValuesMultiTest, TestSolrDeletionPolicy1, 
XsltUpdateRequestHandlerTest, DebugComponentTest, DisMaxRequestHandlerTest, 
TestQueryUtils, DirectSolrSpellCheckerTest, DocumentAnalysisRequestHandlerTest, 
TermsComponentTest, DocumentBuilderTest, TestIndexingPerformance, 
RequiredFieldsTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, 
JSONWriterTest, UniqFieldsUpdateProcessorFactoryTest, PingRequestHandlerTest, 
TestLFUCache, CleanupOldIndexTest, CollectionReloadTest, 
CollectionsAPIAsyncDistributedZkTest, DeleteLastCustomShardedReplicaTest, 
DeleteNodeTest, DeleteReplicaTest, DistribJoinFromCollectionTest, 
HttpPartitionTest, OverseerStatusTest, OverseerTaskQueueTest, 
RecoveryAfterSoftCommitTest, ReplaceNodeTest, ReplicationFactorTest, 
SSLMigrationTest, ShardSplitTest, TestStressCloudBlindAtomicUpdates]
   [junit4] Completed [618/660 (1!)] on J2 in 382.68s, 5 tests, 1 failure <<< 
FAILURES!

[...truncated 60921 lines...]


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

Reply via email to