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

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.GeneratedConstructorAccessor159.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:1079)  at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:943)  at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)  at 
org.apache.solr.core.CoreContainer.create(CoreContainer.java:917)  at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:555)  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:745)  

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.GeneratedConstructorAccessor159.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:1079)
        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:943)
        at org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)
        at org.apache.solr.core.CoreContainer.create(CoreContainer.java:917)
        at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:555)
        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:745)


        at __randomizedtesting.SeedInfo.seed([25DD1863AABB102C]: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.GeneratedMethodAccessor70.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:745)




Build Log:
[...truncated 12885 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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/init-core-data-001
   [junit4]   2> 1682692 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
   [junit4]   2> 1682692 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields
   [junit4]   2> 1682694 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1682695 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/tempDir-001
   [junit4]   2> 1682696 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1682696 INFO  (Thread-5203) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1682697 INFO  (Thread-5203) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1682701 ERROR (Thread-5203) [    ] 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> 1682796 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:58604
   [junit4]   2> 1682804 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15bf1e6c43d0000, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 1682814 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1682814 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1682815 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@69e2fee1{/solr,null,AVAILABLE}
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@50edccae{/solr,null,AVAILABLE}
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@606463fc{SSL,[ssl, 
http/1.1]}{127.0.0.1:50608}
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.e.j.s.Server Started @1685981ms
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=50608}
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@54afbc54{SSL,[ssl, 
http/1.1]}{127.0.0.1:52701}
   [junit4]   2> 1682818 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.e.j.s.Server Started @1685981ms
   [junit4]   2> 1682819 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=52701}
   [junit4]   2> 1682819 ERROR (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1682819 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 1682819 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1682819 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1682819 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-10T10:28:04.404Z
   [junit4]   2> 1682819 ERROR (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1682820 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 1682820 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1682820 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1682820 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-10T10:28:04.405Z
   [junit4]   2> 1682830 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1682834 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1682842 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1682843 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1682843 INFO  (jetty-launcher-4253-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58604/solr
   [junit4]   2> 1682844 INFO  (jetty-launcher-4253-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58604/solr
   [junit4]   2> 1682870 INFO  (jetty-launcher-4253-thread-2) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1682871 INFO  (jetty-launcher-4253-thread-2) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:50608_solr
   [junit4]   2> 1682871 INFO  (jetty-launcher-4253-thread-1) 
[n:127.0.0.1:52701_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1682872 INFO  (jetty-launcher-4253-thread-2) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.Overseer Overseer 
(id=97937790355701765-127.0.0.1:50608_solr-n_0000000000) starting
   [junit4]   2> 1682872 INFO  (jetty-launcher-4253-thread-1) 
[n:127.0.0.1:52701_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52701_solr
   [junit4]   2> 1682890 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1682904 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1682923 INFO  (jetty-launcher-4253-thread-2) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:50608_solr
   [junit4]   2> 1682925 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1682925 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1683009 INFO  (jetty-launcher-4253-thread-1) 
[n:127.0.0.1:52701_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/tempDir-001/node1/.
   [junit4]   2> 1683009 INFO  (jetty-launcher-4253-thread-2) 
[n:127.0.0.1:50608_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/tempDir-001/node2/.
   [junit4]   2> 1683028 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1683029 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:58604/solr ready
   [junit4]   1> Formatting using clusterid: testClusterID
   [junit4]   2> 1683084 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.h.m.i.MetricsConfig Cannot locate configuration: tried 
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
   [junit4]   2> 1683091 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1683093 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1683107 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-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_47346_hdfs____.8wz9ok/webapp
   [junit4]   2> 1683507 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:47346
   [junit4]   2> 1683589 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1683591 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1683604 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-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_43067_datanode____.paibd3/webapp
   [junit4]   2> 1684033 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:43067
   [junit4]   2> 1684097 WARN  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
   [junit4]   2> 1684104 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
jetty-6.1.26
   [junit4]   2> 1684123 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-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_57838_datanode____.u36wv2/webapp
   [junit4]   2> 1684223 INFO  (IPC Server handler 3 on 42399) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-e7cbcd0d-3703-4ee0-b52c-c08cfc63ec7c node 
DatanodeRegistration(127.0.0.1:40574, 
datanodeUuid=007fb202-a32e-4349-871f-5d1b1a446fec, infoPort=38621, 
infoSecurePort=0, ipcPort=57538, 
storageInfo=lv=-56;cid=testClusterID;nsid=644280509;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 1684224 INFO  (IPC Server handler 3 on 42399) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-3be298a7-4df2-4e9e-9b59-4c72fef5be1a node 
DatanodeRegistration(127.0.0.1:40574, 
datanodeUuid=007fb202-a32e-4349-871f-5d1b1a446fec, infoPort=38621, 
infoSecurePort=0, ipcPort=57538, 
storageInfo=lv=-56;cid=testClusterID;nsid=644280509;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 1684584 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] o.m.log 
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:57838
   [junit4]   2> 1684685 INFO  (IPC Server handler 4 on 42399) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-694b13bd-7ea1-49c5-8465-0e4244b5085b node 
DatanodeRegistration(127.0.0.1:49770, 
datanodeUuid=1fecdfbc-ed46-4611-b60d-1cf841ce94d0, infoPort=54952, 
infoSecurePort=0, ipcPort=57152, 
storageInfo=lv=-56;cid=testClusterID;nsid=644280509;c=0), blocks: 0, 
hasStaleStorage: true, processing time: 0 msecs
   [junit4]   2> 1684685 INFO  (IPC Server handler 4 on 42399) [    ] 
BlockStateChange BLOCK* processReport: from storage 
DS-03a3a477-f7bd-4e5c-8346-5c7d9ef0f683 node 
DatanodeRegistration(127.0.0.1:49770, 
datanodeUuid=1fecdfbc-ed46-4611-b60d-1cf841ce94d0, infoPort=54952, 
infoSecurePort=0, ipcPort=57152, 
storageInfo=lv=-56;cid=testClusterID;nsid=644280509;c=0), blocks: 0, 
hasStaleStorage: false, processing time: 0 msecs
   [junit4]   2> 1684852 INFO  
(TEST-HdfsRecoveryZkTest.test-seed#[25DD1863AABB102C]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 1684913 INFO  (qtp205439394-22568) [n:127.0.0.1:52701_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> 1684916 INFO  
(OverseerThreadFactory-6661-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
recoverytest
   [junit4]   2> 1685042 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1685043 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 1685100 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1685100 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 1685209 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_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> 1685210 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_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> 1686067 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 1686077 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema 
[recoverytest_shard1_replica1] Schema name=minimal
   [junit4]   2> 1686080 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686080 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686088 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:42399/data
   [junit4]   2> 1686089 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 1686089 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1686089 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/tempDir-001/node1/recoverytest_shard1_replica1],
 dataDir=[hdfs://localhost:42399/data/recoverytest/core_node1/data/]
   [junit4]   2> 1686089 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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@3b076c87
   [junit4]   2> 1686090 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node1/data/snapshot_metadata
   [junit4]   2> 1686099 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686099 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686099 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1686116 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1686118 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node1/data
   [junit4]   2> 1686126 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 1686138 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema 
[recoverytest_shard1_replica2] Schema name=minimal
   [junit4]   2> 1686140 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686140 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686141 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:42399/data
   [junit4]   2> 1686142 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
   [junit4]   2> 1686142 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1686142 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_25DD1863AABB102C-001/tempDir-001/node2/recoverytest_shard1_replica2],
 dataDir=[hdfs://localhost:42399/data/recoverytest/core_node2/data/]
   [junit4]   2> 1686142 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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@3b076c87
   [junit4]   2> 1686143 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node2/data/snapshot_metadata
   [junit4]   2> 1686150 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node1/data/index
   [junit4]   2> 1686152 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686152 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686152 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1686185 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686188 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686188 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1686207 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1686211 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node2/data
   [junit4]   2> 1686237 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1686252 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory creating directory factory for path 
hdfs://localhost:42399/data/recoverytest/core_node2/data/index
   [junit4]   2> 1686286 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686286 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686286 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
   [junit4]   2> 1686314 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.b.BlockDirectory Block cache on write is disabled
   [junit4]   2> 1686372 INFO  (IPC Server handler 4 on 42399) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40574 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-694b13bd-7ea1-49c5-8465-0e4244b5085b:NORMAL:127.0.0.1:49770|RBW],
 
ReplicaUC[[DISK]DS-3be298a7-4df2-4e9e-9b59-4c72fef5be1a:NORMAL:127.0.0.1:40574|RBW]]}
 size 0
   [junit4]   2> 1686374 INFO  (IPC Server handler 5 on 42399) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49770 is 
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-3be298a7-4df2-4e9e-9b59-4c72fef5be1a:NORMAL:127.0.0.1:40574|RBW],
 
ReplicaUC[[DISK]DS-03a3a477-f7bd-4e5c-8346-5c7d9ef0f683:NORMAL:127.0.0.1:49770|FINALIZED]]}
 size 0
   [junit4]   2> 1686529 INFO  (IPC Server handler 6 on 42399) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40574 is 
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, 
primaryNodeIndex=-1, 
replicas=[ReplicaUC[[DISK]DS-694b13bd-7ea1-49c5-8465-0e4244b5085b:NORMAL:127.0.0.1:49770|RBW],
 
ReplicaUC[[DISK]DS-e7cbcd0d-3703-4ee0-b52c-c08cfc63ec7c:NORMAL:127.0.0.1:40574|FINALIZED]]}
 size 0
   [junit4]   2> 1686533 INFO  (IPC Server handler 0 on 42399) [    ] 
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:49770 is 
added to blk_1073741826_1002 size 71
   [junit4]   2> 1686646 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 1686646 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686646 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 1686672 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 1686672 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 1686719 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
   [junit4]   2> 1686719 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686719 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.HdfsUpdateLog 
Initializing HdfsUpdateLog: tlogDfsReplication=3
   [junit4]   2> 1686748 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3c8ef8d3[recoverytest_shard1_replica1] main]
   [junit4]   2> 1686752 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1686753 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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> 1686753 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1686754 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 1686754 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 1686758 INFO  
(searcherExecutor-6666-thread-1-processing-n:127.0.0.1:52701_solr 
x:recoverytest_shard1_replica1 s:shard1 c:recoverytest) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SolrCore 
[recoverytest_shard1_replica1] Registered new searcher 
Searcher@3c8ef8d3[recoverytest_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1686767 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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 
1567004649955786752
   [junit4]   2> 1686773 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 1686797 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@750da729[recoverytest_shard1_replica2] main]
   [junit4]   2> 1686799 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1686799 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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> 1686800 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1686810 INFO  
(searcherExecutor-6667-thread-1-processing-n:127.0.0.1:50608_solr 
x:recoverytest_shard1_replica2 s:shard1 c:recoverytest) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica2] o.a.s.c.SolrCore 
[recoverytest_shard1_replica2] Registered new searcher 
Searcher@750da729[recoverytest_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1686835 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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 
1567004650027089920
   [junit4]   2> 1686876 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_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> 1686876 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_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> 1687274 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1687274 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1687274 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy 
Sync replicas to https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/
   [junit4]   2> 1687274 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.PeerSync 
PeerSync: core=recoverytest_shard1_replica1 url=https://127.0.0.1:52701/solr 
START replicas=[https://127.0.0.1:50608/solr/recoverytest_shard1_replica2/] 
nUpdates=100
   [junit4]   2> 1687274 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.u.PeerSync 
PeerSync: core=recoverytest_shard1_replica1 url=https://127.0.0.1:52701/solr 
DONE.  We have no versions.  sync failed.
   [junit4]   2> 1687280 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.c.S.Request [recoverytest_shard1_replica2]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1687280 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy 
Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 1687280 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 1687280 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1687284 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/ shard1
   [junit4]   2> 1687387 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_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> 1687388 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_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> 1687437 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1  x:recoverytest_shard1_replica1] o.a.s.c.ZkController I 
am the leader, no recovery necessary
   [junit4]   2> 1687455 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_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=2412
   [junit4]   2> 1687556 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_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> 1687556 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_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> 1687845 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_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=2744
   [junit4]   2> 1687851 INFO  (qtp205439394-22568) [n:127.0.0.1:52701_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> 1687949 INFO  
(zkCallback-4264-thread-1-processing-n:127.0.0.1:50608_solr) 
[n:127.0.0.1:50608_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> 1687949 INFO  
(zkCallback-4265-thread-1-processing-n:127.0.0.1:52701_solr) 
[n:127.0.0.1:52701_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> 1688851 INFO  (qtp205439394-22568) [n:127.0.0.1:52701_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=3938
   [junit4]   2> 1688863 INFO  
(TEST-HdfsRecoveryZkTest.test-seed#[25DD1863AABB102C]) [    ] 
o.a.s.c.RecoveryZkTest Indexing 1200 documents
   [junit4]   2> 1688934 INFO  
(OverseerCollectionConfigSetProcessor-97937790355701765-127.0.0.1:50608_solr-n_0000000000)
 [n:127.0.0.1:50608_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 1689023 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-0
 (1567004652225953792)]} 0 78
   [junit4]   2> 1689023 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0 
(1567004652225953792)]} 0 91
   [junit4]   2> 1689025 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-0
 (1567004652228050944)]} 0 75
   [junit4]   2> 1689025 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0 
(1567004652228050944)]} 0 91
   [junit4]   2> 1689028 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-1
 (1567004652324519936)]} 0 0
   [junit4]   2> 1689030 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1 
(1567004652324519936)]} 0 4
   [junit4]   2> 1689031 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-1
 (1567004652326617088)]} 0 0
   [junit4]   2> 1689032 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1 
(1567004652326617088)]} 0 4
   [junit4]   2> 1689035 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-1
 (-1567004652330811392)]} 0 0
   [junit4]   2> 1689036 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-1 
(-1567004652330811392)]} 0 4
   [junit4]   2> 1689037 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-1
 (-1567004652332908544)]} 0 1
   [junit4]   2> 1689038 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-1 
(-1567004652332908544)]} 0 3
   [junit4]   2> 1689043 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-2
 (1567004652339200000)]} 0 1
   [junit4]   2> 1689044 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2 
(1567004652339200000)]} 0 3
   [junit4]   2> 1689045 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-2
 (1567004652339200001)]} 0 1
   [junit4]   2> 1689046 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2 
(1567004652339200001)]} 0 5
   [junit4]   2> 1689049 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-3
 (1567004652346540032)]} 0 0
   [junit4]   2> 1689049 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3 
(1567004652346540032)]} 0 2
   [junit4]   2> 1689057 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-3
 (1567004652348637184)]} 0 1
   [junit4]   2> 1689058 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3 
(1567004652348637184)]} 0 9
   [junit4]   2> 1689060 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-4
 (1567004652357025792)]} 0 0
   [junit4]   2> 1689060 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4 
(1567004652357025792)]} 0 3
   [junit4]   2> 1689073 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-4
 (-1567004652370657280)]} 0 1
   [junit4]   2> 1689073 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-4
 (1567004652370657281)]} 0 1
   [junit4]   2> 1689074 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4 
(1567004652370657281)]} 0 4
   [junit4]   2> 1689074 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-4 
(-1567004652370657280)]} 0 4
   [junit4]   2> 1689093 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-5
 (1567004652376948737)]} 0 4
   [junit4]   2> 1689094 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5 
(1567004652376948737)]} 0 18
   [junit4]   2> 1689094 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-4
 (-1567004652376948736)]} 0 10
   [junit4]   2> 1689096 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-4 
(-1567004652376948736)]} 0 20
   [junit4]   2> 1689102 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-5
 (1567004652401065984)]} 0 1
   [junit4]   2> 1689103 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5 
(1567004652401065984)]} 0 4
   [junit4]   2> 1689103 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-6
 (1567004652397920256)]} 0 1
   [junit4]   2> 1689103 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6 
(1567004652397920256)]} 0 7
   [junit4]   2> 1689108 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-6
 (1567004652407357440)]} 0 1
   [junit4]   2> 1689108 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-5
 (-1567004652407357441)]} 0 1
   [junit4]   2> 1689108 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6 
(1567004652407357440)]} 0 3
   [junit4]   2> 1689109 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-5 
(-1567004652407357441)]} 0 3
   [junit4]   2> 1689114 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-5
 (-1567004652412600320)]} 0 1
   [junit4]   2> 1689114 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-7
 (1567004652413648896)]} 0 1
   [junit4]   2> 1689114 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7 
(1567004652413648896)]} 0 3
   [junit4]   2> 1689115 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-5 
(-1567004652412600320)]} 0 4
   [junit4]   2> 1689119 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-8
 (1567004652419940352)]} 0 0
   [junit4]   2> 1689119 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8 
(1567004652419940352)]} 0 3
   [junit4]   2> 1689127 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-7
 (1567004652419940353)]} 0 8
   [junit4]   2> 1689128 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7 
(1567004652419940353)]} 0 10
   [junit4]   2> 1689129 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-6
 (-1567004652425183232)]} 0 0
   [junit4]   2> 1689130 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-6 
(-1567004652425183232)]} 0 7
   [junit4]   2> 1689134 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-8
 (1567004652433571840)]} 0 2
   [junit4]   2> 1689135 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-9
 (1567004652434620416)]} 0 0
   [junit4]   2> 1689135 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8 
(1567004652433571840)]} 0 5
   [junit4]   2> 1689135 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9 
(1567004652434620416)]} 0 3
   [junit4]   2> 1689141 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-6
 (-1567004652440911872)]} 0 0
   [junit4]   2> 1689141 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-6 
(-1567004652440911872)]} 0 4
   [junit4]   2> 1689143 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-10
 (1567004652441960448)]} 0 1
   [junit4]   2> 1689143 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10 
(1567004652441960448)]} 0 5
   [junit4]   2> 1689148 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-9
 (1567004652447203328)]} 0 2
   [junit4]   2> 1689148 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9 
(1567004652447203328)]} 0 5
   [junit4]   2> 1689149 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-11
 (1567004652449300480)]} 0 1
   [junit4]   2> 1689150 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11 
(1567004652449300480)]} 0 4
   [junit4]   2> 1689154 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-10
 (1567004652455591936)]} 0 0
   [junit4]   2> 1689154 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10 
(1567004652455591936)]} 0 3
   [junit4]   2> 1689156 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-12
 (1567004652456640512)]} 0 0
   [junit4]   2> 1689156 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-12 
(1567004652456640512)]} 0 4
   [junit4]   2> 1689183 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-11
 (1567004652460834816)]} 0 24
   [junit4]   2> 1689183 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11 
(1567004652460834816)]} 0 27
   [junit4]   2> 1689184 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-7
 (-1567004652463980544)]} 0 23
   [junit4]   2> 1689184 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-7 
(-1567004652463980544)]} 0 25
   [junit4]   2> 1689189 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-13
 (1567004652492292096)]} 0 1
   [junit4]   2> 1689190 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-13 
(1567004652492292096)]} 0 4
   [junit4]   2> 1689190 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-12
 (1567004652492292097)]} 0 0
   [junit4]   2> 1689191 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-12 
(1567004652492292097)]} 0 4
   [junit4]   2> 1689196 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-9
 (-1567004652498583552)]} 0 1
   [junit4]   2> 1689196 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-7
 (-1567004652499632128)]} 0 1
   [junit4]   2> 1689201 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-7 
(-1567004652499632128)]} 0 7
   [junit4]   2> 1689201 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-9 
(-1567004652498583552)]} 0 9
   [junit4]   2> 1689207 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-13
 (1567004652511166465)]} 0 1
   [junit4]   2> 1689208 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-13 
(1567004652511166465)]} 0 3
   [junit4]   2> 1689208 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-14
 (1567004652511166464)]} 0 1
   [junit4]   2> 1689209 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-14 
(1567004652511166464)]} 0 5
   [junit4]   2> 1689213 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-9
 (-1567004652517457920)]} 0 1
   [junit4]   2> 1689213 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-9 
(-1567004652517457920)]} 0 3
   [junit4]   2> 1689213 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-15
 (1567004652518506496)]} 0 0
   [junit4]   2> 1689214 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-15 
(1567004652518506496)]} 0 3
   [junit4]   2> 1689219 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-14
 (1567004652522700800)]} 0 1
   [junit4]   2> 1689219 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-14 
(1567004652522700800)]} 0 4
   [junit4]   2> 1689220 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-12
 (-1567004652523749376)]} 0 1
   [junit4]   2> 1689221 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-12 
(-1567004652523749376)]} 0 4
   [junit4]   2> 1689234 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-15
 (1567004652528992256)]} 0 6
   [junit4]   2> 1689234 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-15 
(1567004652528992256)]} 0 12
   [junit4]   2> 1689235 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-16
 (1567004652532137984)]} 0 7
   [junit4]   2> 1689238 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-16 
(1567004652532137984)]} 0 13
   [junit4]   2> 1689243 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-17
 (1567004652548915200)]} 0 1
   [junit4]   2> 1689243 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-17 
(1567004652548915200)]} 0 3
   [junit4]   2> 1689244 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-12
 (-1567004652549963776)]} 0 1
   [junit4]   2> 1689244 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-12 
(-1567004652549963776)]} 0 3
   [junit4]   2> 1689248 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-18
 (1567004652554158080)]} 0 0
   [junit4]   2> 1689249 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-18 
(1567004652554158080)]} 0 3
   [junit4]   2> 1689249 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-16
 (1567004652555206656)]} 0 1
   [junit4]   2> 1689249 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-16 
(1567004652555206656)]} 0 3
   [junit4]   2> 1689254 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-14
 (-1567004652560449536)]} 0 0
   [junit4]   2> 1689255 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-14 
(-1567004652560449536)]} 0 3
   [junit4]   2> 1689257 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-17
 (1567004652562546688)]} 0 0
   [junit4]   2> 1689257 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-17 
(1567004652562546688)]} 0 4
   [junit4]   2> 1689260 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-19
 (1567004652566740992)]} 0 0
   [junit4]   2> 1689262 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-19 
(1567004652566740992)]} 0 4
   [junit4]   2> 1689263 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-18
 (1567004652569886720)]} 0 1
   [junit4]   2> 1689263 INFO  (qtp205439394-22565) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-18 
(1567004652569886720)]} 0 3
   [junit4]   2> 1689269 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-17
 (-1567004652574081024)]} 0 2
   [junit4]   2> 1689270 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-14
 (-1567004652575129600)]} 0 1
   [junit4]   2> 1689270 INFO  (qtp205439394-22577) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-17 
(-1567004652574081024)]} 0 5
   [junit4]   2> 1689270 INFO  (qtp205439394-22578) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-14 
(-1567004652575129600)]} 0 5
   [junit4]   2> 1689277 INFO  (qtp1772067835-22554) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-20
 (1567004652582469632)]} 0 1
   [junit4]   2> 1689277 INFO  (qtp1772067835-22557) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-19
 (1567004652583518208)]} 0 2
   [junit4]   2> 1689278 INFO  (qtp205439394-22569) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-20 
(1567004652582469632)]} 0 5
   [junit4]   2> 1689278 INFO  (qtp205439394-22579) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-19 
(1567004652583518208)]} 0 5
   [junit4]   2> 1689286 INFO  (qtp1772067835-22559) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-17
 (-1567004652592955392)]} 0 2
   [junit4]   2> 1689287 INFO  (qtp205439394-22563) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-17 
(-1567004652592955392)]} 0 5
   [junit4]   2> 1689288 INFO  (qtp1772067835-22558) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-21
 (1567004652592955393)]} 0 3
   [junit4]   2> 1689288 INFO  (qtp205439394-22572) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-21 
(1567004652592955393)]} 0 5
   [junit4]   2> 1689293 INFO  (qtp1772067835-22556) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-22
 (1567004652601344001)]} 0 0
   [junit4]   2> 1689293 INFO  (qtp1772067835-22555) [n:127.0.0.1:50608_solr 
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica2] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2]  
webapp=/solr path=/update 
params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:52701/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-20
 (1567004652601344000)]} 0 1
   [junit4]   2> 1689293 INFO  (qtp205439394-22564) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-22 
(1567004652601344001)]} 0 3
   [junit4]   2> 1689293 INFO  (qtp205439394-22562) [n:127.0.0.1:52701_solr 
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica1] 
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1]  
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-20 
(1567004652601344000)]} 0 3
   [junit4]   2> 168

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

.ReferenceQueue.remove(ReferenceQueue.java:143)
   [junit4]   2>     
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
   [junit4]   2>     
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
   [junit4]   2> 
   [junit4]   2> IPC Parameter Sending Thread #5:
   [junit4]   2>     [...sun.*]
   [junit4]   2>     
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2>     
java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]   2>     
java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]   2>     
java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]   2>     
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]   2>     
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2>     
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>     java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> RMI Reaper:
   [junit4]   2>     java.lang.Object.wait(Native Method)
   [junit4]   2>     
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
   [junit4]   2>     
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
   [junit4]   2>     [...sun.*]
   [junit4]   2>     java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 1726033 INFO  
(SUITE-HdfsRecoveryZkTest-seed#[25DD1863AABB102C]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ------------------------------------------------------- 
Done waiting for tracked resources to be released
   [junit4]   2> NOTE: test params are: 
codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=22240, maxDocsPerChunk=1, blockSize=8), 
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=22240, blockSize=8)), 
sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=sk-SK, 
timezone=Africa/Lusaka
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_121 (64-bit)/cpus=4,threads=2,free=155947456,total=523239424
   [junit4]   2> NOTE: All tests run in this JVM: 
[TestFuzzyAnalyzedSuggestions, TestFieldResource, ChangedSchemaMergeTest, 
FileUtilsTest, TestSha256AuthenticationProvider, TestBlendedInfixSuggestions, 
HLLUtilTest, TestConfigSetsAPIExclusivity, TestQueryWrapperFilter, 
TestRandomRequestDistribution, TestSolrQueryParserResource, 
TestComplexPhraseLeadingWildcard, SortByFunctionTest, InfixSuggestersTest, 
TestTrackingShardHandlerFactory, TestTolerantUpdateProcessorCloud, 
ChaosMonkeySafeLeaderTest, TestLeaderElectionZkExpiry, HdfsThreadLeakTest, 
TestSweetSpotSimilarityFactory, TestFieldSortValues, TestCoreContainer, 
TestLuceneMatchVersion, AddBlockUpdateTest, TestSolrCLIRunExample, 
CoreAdminRequestStatusTest, DistributedQueueTest, TestBM25SimilarityFactory, 
TestHalfAndHalfDocValues, TestDistributedStatsComponentCardinality, 
TestConfigSets, TestExclusionRuleCollectionAccess, TestSubQueryTransformer, 
TestJsonFacets, EchoParamsTest, TestSearcherReuse, TestDocTermOrds, 
MoveReplicaTest, CollectionStateFormat2Test, ClassificationUpdateProcessorTest, 
ForceLeaderTest, TestBulkSchemaAPI, TestConfigReload, TestSurroundQueryParser, 
TestCloudNestedDocsSort, TestInPlaceUpdatesDistrib, MoreLikeThisHandlerTest, 
TestPartialUpdateDeduplication, TestReRankQParserPlugin, SystemInfoHandlerTest, 
TestExactSharedStatsCache, IndexBasedSpellCheckerTest, TestHashQParserPlugin, 
SpatialFilterTest, JsonValidatorTest, AtomicUpdatesTest, 
TestSchemaNameResource, TestShardHandlerFactory, TestScoreJoinQPScore, 
TestCloudDeleteByQuery, OverseerTaskQueueTest, SolrJmxReporterTest, 
TestOverriddenPrefixQueryForCustomFieldType, TestStandardQParsers, 
TestSimpleTrackingShardHandler, TriLevelCompositeIdRoutingTest, 
LeaderInitiatedRecoveryOnShardRestartTest, TestEmbeddedSolrServerConstructors, 
ConjunctionSolrSpellCheckerTest, VersionInfoTest, TestClusterProperties, 
DirectSolrConnectionTest, SolrIndexConfigTest, 
SchemaVersionSpecificBehaviorTest, TestRequestForwarding, 
TestSolrCoreSnapshots, CheckHdfsIndexTest, TestDistributedGrouping, 
TestHighFrequencyDictionaryFactory, DistributedDebugComponentTest, 
DistributedTermsComponentTest, TestSystemIdResolver, TestQuerySenderListener, 
TestFieldCacheSanityChecker, TestRawTransformer, TestFiltering, LargeFieldTest, 
TestFastOutputStream, TestUpdate, UpdateRequestProcessorFactoryTest, 
TestSolrCloudWithDelegationTokens, SmileWriterTest, 
TestStressCloudBlindAtomicUpdates, HdfsWriteToMultipleCollectionsTest, 
SortSpecParsingTest, ConvertedLegacyTest, TestHashPartitioner, 
TestDynamicLoading, CollectionsAPISolrJTest, TestTrie, DocValuesTest, 
BasicAuthIntegrationTest, SuggesterFSTTest, DataDrivenBlockJoinTest, 
TestManagedSynonymFilterFactory, TestStressVersions, 
HdfsBasicDistributedZkTest, DirectSolrSpellCheckerTest, 
TestSortByMinMaxFunction, TestMiniSolrCloudClusterSSL, TestLockTree, 
RAMDirectoryFactoryTest, ZkSolrClientTest, DocumentBuilderTest, 
TestSchemaVersionResource, TestMissingGroups, TestFaceting, TestRecovery, 
TestStressReorder, StatsComponentTest, SimplePostToolTest, 
TestExtendedDismaxParser, SolrRequestParserTest, SuggesterTest, 
SuggesterWFSTTest, PolyFieldTest, SolrCoreCheckLockOnStartupTest, 
TestAtomicUpdateErrorCases, QueryEqualityTest, TestRemoteStreaming, 
TestSolrDeletionPolicy1, DebugComponentTest, CacheHeaderTest, 
DisMaxRequestHandlerTest, TestQueryUtils, StandardRequestHandlerTest, 
TestQueryTypes, PrimitiveFieldTypeTest, RequestHandlersTest, 
PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, 
IndexSchemaRuntimeFieldTest, LoggingHandlerTest, IndexSchemaTest, 
MBeansHandlerTest, BinaryUpdateRequestHandlerTest, SearchHandlerTest, 
TestQuerySenderNoQuery, ResponseLogComponentTest, BadComponentTest, SampleTest, 
TestElisionMultitermQuery, TestCharFilters, TestCodecSupport, 
TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, DateMathParserTest, 
PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, 
SpellingQueryConverterTest, DOMUtilTest, TestLRUCache, TestDocumentBuilder, 
ZkNodePropsTest, SliceStateTest, DistributedMLTComponentTest, TestRTGBase, 
CursorPagingTest, DistributedIntervalFacetingTest, CdcrRequestHandlerTest, 
CleanupOldIndexTest, ConcurrentDeleteAndCreateCollectionTest, 
ConnectionManagerTest, CreateCollectionCleanupTest, DeleteInactiveReplicaTest, 
DeleteNodeTest, DistribCursorPagingTest, HttpPartitionTest, 
RemoteQueryErrorTest, RestartWhileUpdatingTest, SaslZkACLProviderTest, 
SharedFSAutoReplicaFailoverUtilsTest, SimpleCollectionCreateDeleteTest, 
SolrXmlInZkTest, TestAuthenticationFramework, TestCloudInspectUtil, 
TestCloudJSONFacetJoinDomain, TestCloudRecovery, TestConfigSetsAPIZkFailure, 
TestCryptoKeys, TestHdfsCloudBackupRestore, TestMiniSolrCloudCluster, 
TestShortCircuitedRequests, TestSizeLimitedDistributedMap, 
TestSolrCloudWithSecureImpersonation, TestStressLiveNodes, 
VMParamsZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZk2Test, 
HdfsChaosMonkeySafeLeaderTest, HdfsCollectionsAPIDistributedZkTest, 
HdfsNNFailoverTest, HdfsRecoveryZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HdfsRecoveryZkTest 
-Dtests.seed=25DD1863AABB102C -Dtests.multiplier=2 -Dtests.slow=true 
-Dtests.locale=sk-SK -Dtests.timezone=Africa/Lusaka -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J1 | 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:1079)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:943)
   [junit4]    >        at 
org.apache.solr.core.SolrCore.<init>(SolrCore.java:830)
   [junit4]    >        at 
org.apache.solr.core.CoreContainer.create(CoreContainer.java:917)
   [junit4]    >        at 
org.apache.solr.core.CoreContainer.lambda$load$5(CoreContainer.java:555)
   [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:745)
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([25DD1863AABB102C]:0)
   [junit4]    >        at 
org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:302)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4] Completed [559/711 (1!)] on J1 in 43.41s, 1 test, 1 failure <<< 
FAILURES!

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

Reply via email to