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

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest

Error Message:
ObjectTracker found 1 object(s) that were not released!!! [HdfsTransactionLog] 
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: 
org.apache.solr.update.HdfsTransactionLog  at 
org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
  at 
org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)  
at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203)  at 
org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:153)  at 
org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:110)  at 
org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:108)
  at sun.reflect.GeneratedConstructorAccessor214.newInstance(Unknown Source)  
at 
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
  at java.lang.reflect.Constructor.newInstance(Constructor.java:423)  at 
org.apache.solr.core.SolrCore.createInstance(SolrCore.java:760)  at 
org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:822)  at 
org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1088)  at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:947)  at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)  at 
org.apache.solr.core.CoreContainer.create(CoreContainer.java:930)  at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:565)  at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
  at java.util.concurrent.FutureTask.run(FutureTask.java:266)  at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
  at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 
 at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 
 at java.lang.Thread.run(Thread.java:748)  

Stack Trace:
java.lang.AssertionError: ObjectTracker found 1 object(s) that were not 
released!!! [HdfsTransactionLog]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: 
org.apache.solr.update.HdfsTransactionLog
        at 
org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
        at 
org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
        at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203)
        at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:153)
        at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:110)
        at 
org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:108)
        at sun.reflect.GeneratedConstructorAccessor214.newInstance(Unknown 
Source)
        at 
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:760)
        at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:822)
        at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1088)
        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:947)
        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)
        at org.apache.solr.core.CoreContainer.create(CoreContainer.java:930)
        at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:565)
        at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)


        at __randomizedtesting.SeedInfo.seed([BCA2310878F64125]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertNull(Assert.java:551)
        at 
org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:302)
        at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 12772 lines...]
   [junit4] Suite: org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/init-core-data-001
   [junit4]   2> 1517421 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=76 numCloses=76
   [junit4]   2> 1517421 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 1517422 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1517423 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/tempDir-001
   [junit4]   2> 1517423 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1517423 INFO  (Thread-4698) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1517423 INFO  (Thread-4698) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1517425 ERROR (Thread-4698) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 1517523 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:35523
   [junit4]   2> 1517542 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1517542 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1517548 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@4d20e428{/solr,null,AVAILABLE}
   [junit4]   2> 1517552 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@33014f6b{/solr,null,AVAILABLE}
   [junit4]   2> 1517552 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@7d269a6d{SSL,[ssl, 
http/1.1]}{127.0.0.1:33316}
   [junit4]   2> 1517552 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.e.j.s.Server Started @1519297ms
   [junit4]   2> 1517552 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=33316}
   [junit4]   2> 1517552 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@2c69db23{SSL,[ssl, 
http/1.1]}{127.0.0.1:46207}
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.e.j.s.Server Started @1519297ms
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=46207}
   [junit4]   2> 1517553 ERROR (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1517553 ERROR (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.7.0
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.7.0
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-26T06:51:11.546Z
   [junit4]   2> 1517553 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-26T06:51:11.546Z
   [junit4]   2> 1517555 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1517555 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1517560 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1517560 INFO  (jetty-launcher-2972-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35523/solr
   [junit4]   2> 1517568 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1517568 INFO  (jetty-launcher-2972-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35523/solr
   [junit4]   2> 1517588 INFO  (jetty-launcher-2972-thread-2) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1517588 INFO  (jetty-launcher-2972-thread-1) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1517589 INFO  (jetty-launcher-2972-thread-2) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:46207_solr
   [junit4]   2> 1517590 INFO  (jetty-launcher-2972-thread-1) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33316_solr
   [junit4]   2> 1517590 INFO  (jetty-launcher-2972-thread-2) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.Overseer Overseer 
(id=98203066133184517-127.0.0.1:46207_solr-n_0000000000) starting
   [junit4]   2> 1517592 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1517597 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1517609 INFO  (jetty-launcher-2972-thread-2) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:46207_solr
   [junit4]   2> 1517609 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1517613 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1517648 INFO  (jetty-launcher-2972-thread-1) 
[n:127.0.0.1:33316_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/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/tempDir-001/node1/.
   [junit4]   2> 1517730 INFO  (jetty-launcher-2972-thread-2) 
[n:127.0.0.1:46207_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/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/tempDir-001/node2/.
   [junit4]   2> 1517739 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1517739 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35523/solr ready
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 1517781 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.h.m.i.MetricsConfig Cannot locate configuration: tried 
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 1517789 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1517792 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1517809 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs
 to ./temp/Jetty_localhost_35731_hdfs____pi4gd9/webapp
   [junit4]   2> 1518131 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:35731
   [junit4]   2> 1518279 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1518280 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1518290 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_60652_datanode____dx8ts0/webapp
   [junit4]   2> 1518645 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:60652
   [junit4]   2> 1518734 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1518757 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1518798 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Extract 
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
 to ./temp/Jetty_localhost_39306_datanode____vhcjp6/webapp
   [junit4]   2> 1519151 INFO  (IPC Server handler 2 on 38875) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-8014be02-06e6-4c05-8714-ddc1fcaf0c8d node 
DatanodeRegistration(127.0.0.1:50597, 
datanodeUuid=d656692b-c398-4bc8-b628-8288a2181aa5, infoPort=48744, 
infoSecurePort=0, ipcPort=50336, 
storageInfo=lv=-56;cid=testClusterID;nsid=1447256156;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 1519151 INFO  (IPC Server handler 2 on 38875) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-09d4b590-1475-468a-9226-c0659ad98a6f node 
DatanodeRegistration(127.0.0.1:50597, 
datanodeUuid=d656692b-c398-4bc8-b628-8288a2181aa5, infoPort=48744, 
infoSecurePort=0, ipcPort=50336, 
storageInfo=lv=-56;cid=testClusterID;nsid=1447256156;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 1519266 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:39306
   [junit4]   2> 1519437 INFO  (IPC Server handler 5 on 38875) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-92b17616-269f-4057-8f61-7d25399e87ad node 
DatanodeRegistration(127.0.0.1:43020, 
datanodeUuid=4445a2d4-58ae-49ce-8b24-86f0f254c251, infoPort=51440, 
infoSecurePort=0, ipcPort=53231, 
storageInfo=lv=-56;cid=testClusterID;nsid=1447256156;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 1519437 INFO  (IPC Server handler 5 on 38875) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-2dac493a-f87f-4ea8-bb49-ac920c4a056e node 
DatanodeRegistration(127.0.0.1:43020, 
datanodeUuid=4445a2d4-58ae-49ce-8b24-86f0f254c251, infoPort=51440, 
infoSecurePort=0, ipcPort=53231, 
storageInfo=lv=-56;cid=testClusterID;nsid=1447256156;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 1519604 INFO  
(TEST-HdfsRecoveryZkTest.test-seed#[BCA2310878F64125]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 1519671 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1519680 INFO  
(OverseerThreadFactory-5839-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
recoverytest
   [junit4]   2> 1519821 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1519821 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 1519864 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1519865 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 1519967 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1519968 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1520839 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.7.0
   [junit4]   2> 1520845 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema 
[recoverytest_shard1_replica2] Schema name=minimal
   [junit4]   2> 1520847 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema 
Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1520847 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.CoreContainer 
Creating SolrCore 'recoverytest_shard1_replica2' using configuration from 
collection recoverytest, trusted=true
   [junit4]   2> 1520852 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:38875/data
   [junit4]   2> 1520852 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 1520852 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1520852 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrCore 
[[recoverytest_shard1_replica2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/tempDir-001/node1/recoverytest_shard1_replica2],
 dataDir=[hdfs://localhost:38875/data/recoverytest/core_node1/data/]
   [junit4]   2> 1520853 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3233386
   [junit4]   2> 1520853 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node1/data/snapshot_metadata
   [junit4]   2> 1520859 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 1520859 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[16777216] will allocate [1] slabs and use ~[16777216] bytes
   [junit4]   2> 1520859 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1520877 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.7.0
   [junit4]   2> 1520884 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema 
[recoverytest_shard1_replica1] Schema name=minimal
   [junit4]   2> 1520907 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema 
Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1520907 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.CoreContainer 
Creating SolrCore 'recoverytest_shard1_replica1' using configuration from 
collection recoverytest, trusted=true
   [junit4]   2> 1520908 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:38875/data
   [junit4]   2> 1520908 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 1520908 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1520908 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrCore 
[[recoverytest_shard1_replica1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.x/solr/build/solr-core/test/J0/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_BCA2310878F64125-001/tempDir-001/node2/recoverytest_shard1_replica1],
 dataDir=[hdfs://localhost:38875/data/recoverytest/core_node2/data/]
   [junit4]   2> 1520908 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3233386
   [junit4]   2> 1520909 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node2/data/snapshot_metadata
   [junit4]   2> 1520918 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1520919 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node1/data
   [junit4]   2> 1520936 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 1520936 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[16777216] will allocate [1] slabs and use ~[16777216] bytes
   [junit4]   2> 1520936 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1520968 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node1/data/index
   [junit4]   2> 1520975 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 1520975 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[16777216] will allocate [1] slabs and use ~[16777216] bytes
   [junit4]   2> 1520975 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1521172 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1521175 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node2/data
   [junit4]   2> 1521179 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1521202 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:38875/data/recoverytest/core_node2/data/index
   [junit4]   2> 1521216 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct 
memory allocation set to [true]
   [junit4]   2> 1521218 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of 
[16777216] will allocate [1] slabs and use ~[16777216] bytes
   [junit4]   2> 1521218 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1521234 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1521238 INFO  (IPC Server handler 4 on 38875) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:43020 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-8014be02-06e6-4c05-8714-ddc1fcaf0c8d:NORMAL:127.0.0.1:50597|RBW],
 
ReplicaUC[[DISK]DS-92b17616-269f-4057-8f61-7d25399e87ad:NORMAL:127.0.0.1:43020|RBW]]}
 size 0
   [junit4]   2> 1521244 INFO  (IPC Server handler 6 on 38875) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50597 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-92b17616-269f-4057-8f61-7d25399e87ad:NORMAL:127.0.0.1:43020|RBW],
 
ReplicaUC[[DISK]DS-09d4b590-1475-468a-9226-c0659ad98a6f:NORMAL:127.0.0.1:50597|FINALIZED]]}
 size 0
   [junit4]   2> 1521279 INFO  (IPC Server handler 7 on 38875) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50597 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-92b17616-269f-4057-8f61-7d25399e87ad:NORMAL:127.0.0.1:43020|RBW],
 
ReplicaUC[[DISK]DS-8014be02-06e6-4c05-8714-ddc1fcaf0c8d:NORMAL:127.0.0.1:50597|RBW]]}
 size 0
   [junit4]   2> 1521280 INFO  (IPC Server handler 8 on 38875) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:43020 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-8014be02-06e6-4c05-8714-ddc1fcaf0c8d:NORMAL:127.0.0.1:50597|RBW],
 
ReplicaUC[[DISK]DS-2dac493a-f87f-4ea8-bb49-ac920c4a056e:NORMAL:127.0.0.1:43020|FINALIZED]]}
 size 0
   [junit4]   2> 1521297 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 1521297 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1521297 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 1521315 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 1521315 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 1521320 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 1521320 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1521320 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 1521335 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 1521335 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 1521356 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@4cb20e5a[recoverytest_shard1_replica2] main]
   [junit4]   2> 1521365 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1521365 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1521366 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1521367 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@59001f92[recoverytest_shard1_replica1] main]
   [junit4]   2> 1521369 INFO  
(searcherExecutor-5844-thread-1-processing-n:127.0.0.1:33316_solr 
x:recoverytest_shard1_replica2 s:shard1 c:recoverytest) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrCore 
[recoverytest_shard1_replica2] Registered new searcher 
Searcher@4cb20e5a[recoverytest_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1521371 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1521375 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1521375 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1521376 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1571249062274924544
   [junit4]   2> 1521379 INFO  
(searcherExecutor-5845-thread-1-processing-n:127.0.0.1:46207_solr 
x:recoverytest_shard1_replica1 s:shard1 c:recoverytest) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrCore 
[recoverytest_shard1_replica1] Registered new searcher 
Searcher@59001f92[recoverytest_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1521383 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1571249062282264576
   [junit4]   2> 1521387 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1521387 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1521387 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SyncStrategy 
Sync replicas to https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/
   [junit4]   2> 1521388 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.PeerSync 
PeerSync: core=recoverytest_shard1_replica2 url=https://127.0.0.1:33316/solr 
START replicas=[https://127.0.0.1:46207/solr/recoverytest_shard1_replica1/] 
nUpdates=100
   [junit4]   2> 1521392 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.PeerSync 
PeerSync: core=recoverytest_shard1_replica2 url=https://127.0.0.1:33316/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 1521405 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.c.S.Request [recoverytest_shard1_replica1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1521405 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SyncStrategy 
Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 1521405 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 1521405 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1521408 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/ shard1
   [junit4]   2> 1521510 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1521510 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1521559 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.ZkController I 
am the leader, no recovery necessary
   [junit4]   2> 1521561 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2}
 status=0 QTime=1739
   [junit4]   2> 1521662 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1521662 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1522389 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.s.HttpSolrCall 
[admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2}
 status=0 QTime=2525
   [junit4]   2> 1522392 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_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> 1522493 INFO  
(zkCallback-2983-thread-1-processing-n:127.0.0.1:46207_solr) 
[n:127.0.0.1:46207_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1522493 INFO  
(zkCallback-2984-thread-1-processing-n:127.0.0.1:33316_solr) 
[n:127.0.0.1:33316_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/recoverytest/state.json] for collection [recoverytest] has 
occurred - updating... (live nodes size: [2])
   [junit4]   2> 1523392 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&action=CREATE&numShards=1&wt=javabin&version=2}
 status=0 QTime=3721
   [junit4]   2> 1523394 INFO  
(TEST-HdfsRecoveryZkTest.test-seed#[BCA2310878F64125]) [    ] 
o.a.s.c.RecoveryZkTest Indexing 1200 documents
   [junit4]   2> 1523428 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-0
 (1571249064398290944)]} 0 13
   [junit4]   2> 1523429 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0 
(1571249064398290944)]} 0 27
   [junit4]   2> 1523429 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-0
 (1571249064400388096)]} 0 15
   [junit4]   2> 1523429 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0 
(1571249064400388096)]} 0 25
   [junit4]   2> 1523435 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-0
 (-1571249064429748224)]} 0 2
   [junit4]   2> 1523435 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-0 
(-1571249064429748224)]} 0 4
   [junit4]   2> 1523435 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-0
 (-1571249064428699648)]} 0 0
   [junit4]   2> 1523436 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-0 
(-1571249064428699648)]} 0 5
   [junit4]   2> 1523441 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-1
 (1571249064436039680)]} 0 3
   [junit4]   2> 1523442 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1 
(1571249064436039680)]} 0 4
   [junit4]   2> 1523444 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-1
 (1571249064436039681)]} 0 1
   [junit4]   2> 1523444 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1 
(1571249064436039681)]} 0 7
   [junit4]   2> 1523446 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-2
 (1571249064443379712)]} 0 0
   [junit4]   2> 1523446 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2 
(1571249064443379712)]} 0 2
   [junit4]   2> 1523448 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-2
 (1571249064445476864)]} 0 0
   [junit4]   2> 1523449 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2 
(1571249064445476864)]} 0 2
   [junit4]   2> 1523450 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-3
 (1571249064447574016)]} 0 0
   [junit4]   2> 1523450 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3 
(1571249064447574016)]} 0 2
   [junit4]   2> 1523452 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-3
 (1571249064449671168)]} 0 0
   [junit4]   2> 1523452 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3 
(1571249064449671168)]} 0 2
   [junit4]   2> 1523454 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-1
 (-1571249064451768320)]} 0 0
   [junit4]   2> 1523454 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-1 
(-1571249064451768320)]} 0 2
   [junit4]   2> 1523456 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-1
 (-1571249064453865472)]} 0 0
   [junit4]   2> 1523457 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-1 
(-1571249064453865472)]} 0 2
   [junit4]   2> 1523458 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-4
 (1571249064455962624)]} 0 0
   [junit4]   2> 1523459 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4 
(1571249064455962624)]} 0 2
   [junit4]   2> 1523460 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-4
 (1571249064458059776)]} 0 0
   [junit4]   2> 1523461 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4 
(1571249064458059776)]} 0 2
   [junit4]   2> 1523462 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-5
 (1571249064460156928)]} 0 0
   [junit4]   2> 1523462 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5 
(1571249064460156928)]} 0 2
   [junit4]   2> 1523465 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-5
 (1571249064462254080)]} 0 1
   [junit4]   2> 1523465 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5 
(1571249064462254080)]} 0 3
   [junit4]   2> 1523466 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-6
 (1571249064464351232)]} 0 0
   [junit4]   2> 1523466 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6 
(1571249064464351232)]} 0 2
   [junit4]   2> 1523469 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-6
 (1571249064467496960)]} 0 0
   [junit4]   2> 1523469 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6 
(1571249064467496960)]} 0 2
   [junit4]   2> 1523470 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-2
 (-1571249064468545536)]} 0 0
   [junit4]   2> 1523470 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-2 
(-1571249064468545536)]} 0 2
   [junit4]   2> 1523473 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-2
 (-1571249064471691264)]} 0 0
   [junit4]   2> 1523473 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-2 
(-1571249064471691264)]} 0 2
   [junit4]   2> 1523474 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-7
 (1571249064472739840)]} 0 0
   [junit4]   2> 1523474 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7 
(1571249064472739840)]} 0 2
   [junit4]   2> 1523477 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-7
 (1571249064475885568)]} 0 0
   [junit4]   2> 1523477 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7 
(1571249064475885568)]} 0 2
   [junit4]   2> 1523477 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-6
 (-1571249064476934144)]} 0 0
   [junit4]   2> 1523478 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-6 
(-1571249064476934144)]} 0 2
   [junit4]   2> 1523481 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-6
 (-1571249064480079872)]} 0 0
   [junit4]   2> 1523481 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-6 
(-1571249064480079872)]} 0 2
   [junit4]   2> 1523481 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-8
 (1571249064480079873)]} 0 0
   [junit4]   2> 1523482 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8 
(1571249064480079873)]} 0 2
   [junit4]   2> 1523485 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-8
 (1571249064484274176)]} 0 0
   [junit4]   2> 1523485 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8 
(1571249064484274176)]} 0 2
   [junit4]   2> 1523485 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-9
 (1571249064484274177)]} 0 0
   [junit4]   2> 1523485 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9 
(1571249064484274177)]} 0 2
   [junit4]   2> 1523489 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-9
 (1571249064488468480)]} 0 0
   [junit4]   2> 1523489 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-10
 (1571249064488468481)]} 0 0
   [junit4]   2> 1523489 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9 
(1571249064488468480)]} 0 2
   [junit4]   2> 1523489 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10 
(1571249064488468481)]} 0 2
   [junit4]   2> 1523493 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-10
 (1571249064492662784)]} 0 0
   [junit4]   2> 1523493 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-7
 (-1571249064492662785)]} 0 0
   [junit4]   2> 1523493 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10 
(1571249064492662784)]} 0 2
   [junit4]   2> 1523493 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-7 
(-1571249064492662785)]} 0 2
   [junit4]   2> 1523499 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-11
 (1571249064498954240)]} 0 0
   [junit4]   2> 1523499 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11 
(1571249064498954240)]} 0 2
   [junit4]   2> 1523499 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-7
 (-1571249064498954241)]} 0 0
   [junit4]   2> 1523499 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-7 
(-1571249064498954241)]} 0 2
   [junit4]   2> 1523503 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-12
 (1571249064502099968)]} 0 0
   [junit4]   2> 1523503 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-11
 (1571249064503148544)]} 0 0
   [junit4]   2> 1523503 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-12 
(1571249064502099968)]} 0 2
   [junit4]   2> 1523503 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11 
(1571249064503148544)]} 0 2
   [junit4]   2> 1523506 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-13
 (1571249064506294272)]} 0 0
   [junit4]   2> 1523506 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-12
 (1571249064506294273)]} 0 0
   [junit4]   2> 1523507 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-13 
(1571249064506294272)]} 0 2
   [junit4]   2> 1523507 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-12 
(1571249064506294273)]} 0 2
   [junit4]   2> 1523510 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-14
 (1571249064510488576)]} 0 0
   [junit4]   2> 1523510 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-13
 (1571249064510488577)]} 0 0
   [junit4]   2> 1523510 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-14 
(1571249064510488576)]} 0 2
   [junit4]   2> 1523510 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-13 
(1571249064510488577)]} 0 2
   [junit4]   2> 1523514 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-8
 (-1571249064514682880)]} 0 0
   [junit4]   2> 1523514 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-14
 (1571249064514682881)]} 0 0
   [junit4]   2> 1523514 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-8 
(-1571249064514682880)]} 0 2
   [junit4]   2> 1523514 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-14 
(1571249064514682881)]} 0 2
   [junit4]   2> 1523518 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-8
 (-1571249064518877185)]} 0 0
   [junit4]   2> 1523518 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-15
 (1571249064518877184)]} 0 0
   [junit4]   2> 1523518 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-8 
(-1571249064518877185)]} 0 2
   [junit4]   2> 1523518 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-15 
(1571249064518877184)]} 0 2
   [junit4]   2> 1523522 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-16
 (1571249064523071488)]} 0 0
   [junit4]   2> 1523522 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-15
 (1571249064523071489)]} 0 0
   [junit4]   2> 1523522 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-16 
(1571249064523071488)]} 0 2
   [junit4]   2> 1523522 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-15 
(1571249064523071489)]} 0 2
   [junit4]   2> 1523526 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-17
 (1571249064527265792)]} 0 0
   [junit4]   2> 1523526 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-16
 (1571249064527265793)]} 0 0
   [junit4]   2> 1523526 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-17 
(1571249064527265792)]} 0 2
   [junit4]   2> 1523526 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-16 
(1571249064527265793)]} 0 2
   [junit4]   2> 1523530 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-18
 (1571249064531460096)]} 0 0
   [junit4]   2> 1523530 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-17
 (1571249064531460097)]} 0 0
   [junit4]   2> 1523530 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-18 
(1571249064531460096)]} 0 2
   [junit4]   2> 1523531 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-17 
(1571249064531460097)]} 0 2
   [junit4]   2> 1523534 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-11
 (-1571249064535654400)]} 0 0
   [junit4]   2> 1523534 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-18
 (1571249064535654401)]} 0 0
   [junit4]   2> 1523534 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-11 
(-1571249064535654400)]} 0 2
   [junit4]   2> 1523535 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-18 
(1571249064535654401)]} 0 2
   [junit4]   2> 1523540 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-11
 (-1571249064539848705)]} 0 2
   [junit4]   2> 1523541 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-19
 (1571249064539848704)]} 0 1
   [junit4]   2> 1523541 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-11 
(-1571249064539848705)]} 0 4
   [junit4]   2> 1523541 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-19 
(1571249064539848704)]} 0 4
   [junit4]   2> 1523545 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-19
 (1571249064547188737)]} 0 0
   [junit4]   2> 1523545 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-20
 (1571249064547188736)]} 0 0
   [junit4]   2> 1523545 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-19 
(1571249064547188737)]} 0 2
   [junit4]   2> 1523545 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-20 
(1571249064547188736)]} 0 2
   [junit4]   2> 1523548 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-13
 (-1571249064551383040)]} 0 0
   [junit4]   2> 1523549 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-20
 (1571249064550334464)]} 0 0
   [junit4]   2> 1523549 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-13 
(-1571249064551383040)]} 0 2
   [junit4]   2> 1523549 INFO  (qtp1916847373-15824) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-20 
(1571249064550334464)]} 0 2
   [junit4]   2> 1523552 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-21
 (1571249064554528768)]} 0 0
   [junit4]   2> 1523552 INFO  (qtp337572124-15833) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-13
 (-1571249064554528769)]} 0 0
   [junit4]   2> 1523552 INFO  (qtp1916847373-15827) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-21 
(1571249064554528768)]} 0 2
   [junit4]   2> 1523553 INFO  (qtp1916847373-15832) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-13 
(-1571249064554528769)]} 0 2
   [junit4]   2> 1523556 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-21
 (1571249064558723072)]} 0 0
   [junit4]   2> 1523556 INFO  (qtp337572124-15829) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-22
 (1571249064558723073)]} 0 0
   [junit4]   2> 1523557 INFO  (qtp1916847373-15830) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-21 
(1571249064558723072)]} 0 2
   [junit4]   2> 1523557 INFO  (qtp1916847373-15825) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-22 
(1571249064558723073)]} 0 2
   [junit4]   2> 1523560 INFO  (qtp337572124-15835) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[1-22
 (1571249064562917376)]} 0 0
   [junit4]   2> 1523561 INFO  (qtp1916847373-15834) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-22 
(1571249064562917376)]} 0 2
   [junit4]   2> 1523561 INFO  (qtp337572124-15831) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[2-15
 (-1571249064563965952)]} 0 0
   [junit4]   2> 1523561 INFO  (qtp1916847373-15821) [n:127.0.0.1:33316_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-15 
(-1571249064563965952)]} 0 2
   [junit4]   2> 1523564 INFO  (qtp337572124-15826) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{delete=[1-15
 (-1571249064567111680)]} 0 0
   [junit4]   2> 1523564 INFO  (qtp337572124-15823) [n:127.0.0.1:46207_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33316/solr/recoverytest_shard1_replica2/&wt=javabin&version=2}{add=[2-23
 (1571249064567111681)]} 0 0
   [junit4]   2> 1523564 INFO  (qt

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

eckEmpty(SolrTestCaseJ4.java:355)
   [junit4]   2>     
org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:301)
   [junit4]   2>     [...sun.*, java.lang.reflect.*, 
com.carrotsearch.randomizedtesting.*]
   [junit4]   2>     
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
   [junit4]   2>     [...com.carrotsearch.randomizedtesting.*]
   [junit4]   2>     
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
   [junit4]   2>     [...com.carrotsearch.randomizedtesting.*]
   [junit4]   2>     
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
   [junit4]   2>     
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
   [junit4]   2>     
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
   [junit4]   2>     
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
   [junit4]   2>     [...com.carrotsearch.randomizedtesting.*]
   [junit4]   2>     java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> GC Daemon:
   [junit4]   2>     java.lang.Object.wait(Native Method)
   [junit4]   2>     [...sun.*]
   [junit4]   2> 
   [junit4]   2> LeaseRenewer:jenkins@localhost:38875:
   [junit4]   2>     java.lang.Thread.sleep(Native Method)
   [junit4]   2>     
org.apache.hadoop.hdfs.LeaseRenewer.run(LeaseRenewer.java:444)
   [junit4]   2>     
org.apache.hadoop.hdfs.LeaseRenewer.access$700(LeaseRenewer.java:71)
   [junit4]   2>     
org.apache.hadoop.hdfs.LeaseRenewer$1.run(LeaseRenewer.java:304)
   [junit4]   2>     java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]:
   [junit4]   2>     java.lang.Object.wait(Native Method)
   [junit4]   2>     java.lang.Thread.join(Thread.java:1260)
   [junit4]   2>     [...com.carrotsearch.randomizedtesting.*]
   [junit4]   2> 
   [junit4]   2> RMI TCP Accept-0:
   [junit4]   2>     java.net.PlainSocketImpl.socketAccept(Native Method)
   [junit4]   2>     
java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
   [junit4]   2>     java.net.ServerSocket.implAccept(ServerSocket.java:545)
   [junit4]   2>     java.net.ServerSocket.accept(ServerSocket.java:513)
   [junit4]   2>     [...sun.*]
   [junit4]   2>     java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1555814 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[BCA2310878F64125]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ------------------------------------------------------- 
Done waiting for tracked resources to be released
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): 
{rnd_b=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
_version_=Lucene50(blocksize=128), a_t=Lucene50(blocksize=128), 
a_i=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{}, 
maxPointsInLeafNode=1999, maxMBSortInHeap=5.333987776967699, 
sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=lt-LT, 
timezone=Africa/Lagos
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_131 (64-bit)/cpus=4,threads=2,free=176301640,total=526909440
   [junit4]   2> NOTE: All tests run in this JVM: [TestJmxMonitoredMap, 
TestCloudJSONFacetJoinDomain, ShufflingReplicaListTransformerTest, 
TestRealTimeGet, TestReloadDeadlock, TestRandomDVFaceting, 
PreAnalyzedUpdateProcessorTest, PluginInfoTest, TestInfoStreamLogging, 
DistributedFacetPivotSmallAdvancedTest, SearchHandlerTest, 
TlogReplayBufferedWhileIndexingTest, TestPerFieldSimilarityWithDefaultOverride, 
FacetPivotSmallTest, QueryElevationComponentTest, TestSchemaManager, 
DateMathParserTest, SyncSliceTest, TestSQLHandler, TestReplicationHandler, 
TestCoreAdminApis, TestFuzzyAnalyzedSuggestions, AliasIntegrationTest, 
TestBadConfig, TestJoin, TestSolrQueryResponse, 
TestSubQueryTransformerCrossCore, BasicZkTest, UpdateParamsTest, 
PKIAuthenticationIntegrationTest, TestSolrConfigHandler, TermsComponentTest, 
TestRangeQuery, TestManagedSynonymGraphFilterFactory, BlockDirectoryTest, 
ChangedSchemaMergeTest, LeaderElectionIntegrationTest, TestHdfsUpdateLog, 
TestSuggestSpellingConverter, BigEndianAscendingWordDeserializerTest, 
ClusterStateTest, TestCrossCoreJoin, TestMacros, TestUseDocValuesAsStored2, 
InfoHandlerTest, TestBlobHandler, PrimitiveFieldTypeTest, 
CdcrReplicationHandlerTest, FieldMutatingUpdateProcessorTest, 
TestUniqueKeyFieldResource, TestManagedResourceStorage, CircularListTest, 
SolrIndexSplitterTest, TestCSVLoader, DocValuesNotIndexedTest, 
HdfsLockFactoryTest, LeaderInitiatedRecoveryOnCommitTest, TestStressRecovery, 
TestScoreJoinQPNoScore, TestFreeTextSuggestions, TestLazyCores, 
BadComponentTest, TestAuthenticationFramework, TestGraphTermsQParserPlugin, 
SolrGangliaReporterTest, TestHighlightDedupGrouping, TestCollapseQParserPlugin, 
SuggestComponentTest, TestJettySolrRunner, TestBackupRepositoryFactory, 
TestPayloadScoreQParserPlugin, DistributedQueryElevationComponentTest, 
TestFastWriter, BinaryUpdateRequestHandlerTest, 
TestReversedWildcardFilterFactory, TestHttpShardHandlerFactory, 
TestAnalyzeInfixSuggestions, MissingSegmentRecoveryTest, 
DirectSolrConnectionTest, TestConfigSetProperties, HdfsUnloadDistributedZkTest, 
HdfsRecoverLeaseTest, TestSolrDeletionPolicy1, SampleTest, 
TestSerializedLuceneMatchVersion, TestNamedUpdateProcessors, 
TestSizeLimitedDistributedMap, TestOrdValues, AtomicUpdateProcessorFactoryTest, 
SolrSlf4jReporterTest, OverseerCollectionConfigSetProcessorTest, 
IndexSchemaRuntimeFieldTest, TestTrieFacet, TestSchemaResource, 
ScriptEngineTest, TestFunctionQuery, TestPathTrie, ReplicationFactorTest, 
TestSolrConfigHandlerConcurrent, TestConfigSetsAPI, 
WordBreakSolrSpellCheckerTest, TestCollationFieldDocValues, SolrCLIZkUtilsTest, 
ResponseHeaderTest, DefaultValueUpdateProcessorTest, TestSolrFieldCacheMBean, 
TestXIncludeConfig, DistribJoinFromCollectionTest, BlockJoinFacetDistribTest, 
TestSolrIndexConfig, CursorPagingTest, TestPushWriter, OpenCloseCoreStressTest, 
ShardRoutingTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, 
ClusterStateUpdateTest, TestZkChroot, TestDistributedSearch, 
FileBasedSpellCheckerTest, TestIndexingPerformance, RegexBoostProcessorTest, 
IndexSchemaTest, QueryParsingTest, PingRequestHandlerTest, TestSolrJ, 
DistributedMLTComponentTest, TestTolerantSearch, 
TestEmbeddedSolrServerSchemaAPI, BaseCdcrDistributedZkTest, CdcrBootstrapTest, 
ConfigSetsAPITest, CreateCollectionCleanupTest, CustomCollectionTest, 
DeleteStatusTest, ForceLeaderTest, TestCloudRecovery, TestClusterProperties, 
TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, 
TestDeleteCollectionOnDownNodes, TestDownShardTolerantSearch, 
TestHdfsCloudBackupRestore, TestLocalFSCloudBackupRestore, 
TestOnReconnectListenerSupport, TestRandomFlRTGCloud, TestRebalanceLeaders, 
TestRequestStatusCollectionAPI, TestSolrCloudWithDelegationTokens, 
TestSolrCloudWithSecureImpersonation, TestStressCloudBlindAtomicUpdates, 
HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, 
HdfsChaosMonkeyNothingIsSafeTest, HdfsChaosMonkeySafeLeaderTest, 
HdfsRecoveryZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HdfsRecoveryZkTest 
-Dtests.seed=BCA2310878F64125 -Dtests.multiplier=2 -Dtests.slow=true 
-Dtests.locale=lt-LT -Dtests.timezone=Africa/Lagos -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J0 | HdfsRecoveryZkTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: ObjectTracker found 1 
object(s) that were not released!!! [HdfsTransactionLog]
   [junit4]    > 
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: 
org.apache.solr.update.HdfsTransactionLog
   [junit4]    >        at 
org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
   [junit4]    >        at 
org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
   [junit4]    >        at 
org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:203)
   [junit4]    >        at 
org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:153)
   [junit4]    >        at 
org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:110)
   [junit4]    >        at 
org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:108)
   [junit4]    >        at 
java.lang.reflect.Constructor.newInstance(Constructor.java:423)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.createInstance(SolrCore.java:760)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:822)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1088)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:947)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)
   [junit4]    >        at 
org.apache.solr.core.CoreContainer.create(CoreContainer.java:930)
   [junit4]    >        at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:565)
   [junit4]    >        at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
   [junit4]    >        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]    >        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]    >        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]    >        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >        at java.lang.Thread.run(Thread.java:748)
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([BCA2310878F64125]:0)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:302)
   [junit4]    >        at java.lang.Thread.run(Thread.java:748)
   [junit4] Completed [553/713 (1!)] on J0 in 38.47s, 1 test, 1 failure <<< 
FAILURES!

[...truncated 44039 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to