You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/11/17 06:10:30 UTC
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build # 950
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/950/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
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 at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43) at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130) at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137) at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94) at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102) at sun.reflect.GeneratedConstructorAccessor183.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:723) at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:785) at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1024) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:889) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:793) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:868) at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:517) 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
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43)
at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102)
at sun.reflect.GeneratedConstructorAccessor183.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:723)
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:785)
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1024)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:889)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:793)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:868)
at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:517)
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([B6D9641594DB7180]: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:260)
at sun.reflect.GeneratedMethodAccessor15.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:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 12274 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/init-core-data-001
[junit4] 2> 2371319 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2371319 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/tempDir-001
[junit4] 2> 2371320 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2371320 INFO (Thread-4563) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2371320 INFO (Thread-4563) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2371420 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34846
[junit4] 2> 2371427 INFO (jetty-launcher-9284-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2371428 INFO (jetty-launcher-9284-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 2371429 INFO (jetty-launcher-9284-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e6d6154{/solr,null,AVAILABLE}
[junit4] 2> 2371430 INFO (jetty-launcher-9284-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@7da484f{HTTP/1.1,[http/1.1]}{127.0.0.1:36924}
[junit4] 2> 2371430 INFO (jetty-launcher-9284-thread-1) [ ] o.e.j.s.Server Started @2374940ms
[junit4] 2> 2371430 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36924}
[junit4] 2> 2371430 ERROR (jetty-launcher-9284-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3485f159{/solr,null,AVAILABLE}
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T05:43:49.525Z
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@fb30056{HTTP/1.1,[http/1.1]}{127.0.0.1:40891}
[junit4] 2> 2371431 INFO (jetty-launcher-9284-thread-2) [ ] o.e.j.s.Server Started @2374941ms
[junit4] 2> 2371432 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40891}
[junit4] 2> 2371432 ERROR (jetty-launcher-9284-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2371432 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 2371432 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2371432 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2371432 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-17T05:43:49.526Z
[junit4] 2> 2371436 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2371436 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2371444 INFO (jetty-launcher-9284-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34846/solr
[junit4] 2> 2371444 INFO (jetty-launcher-9284-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34846/solr
[junit4] 2> 2371483 INFO (jetty-launcher-9284-thread-2) [n:127.0.0.1:40891_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40891_solr
[junit4] 2> 2371485 INFO (jetty-launcher-9284-thread-1) [n:127.0.0.1:36924_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36924_solr
[junit4] 2> 2371485 INFO (jetty-launcher-9284-thread-2) [n:127.0.0.1:40891_solr ] o.a.s.c.Overseer Overseer (id=96951430638141446-127.0.0.1:40891_solr-n_0000000000) starting
[junit4] 2> 2371488 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2371488 INFO (zkCallback-9295-thread-1-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2371502 INFO (jetty-launcher-9284-thread-2) [n:127.0.0.1:40891_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40891_solr
[junit4] 2> 2371505 INFO (zkCallback-9295-thread-1-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2371507 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2371617 INFO (jetty-launcher-9284-thread-1) [n:127.0.0.1:36924_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/tempDir-001/node1/.
[junit4] 2> 2371821 INFO (jetty-launcher-9284-thread-2) [n:127.0.0.1:40891_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/tempDir-001/node2/.
[junit4] 2> 2371835 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 2371923 WARN (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 2371932 WARN (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2371955 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2371977 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs to ./temp/Jetty_solaris.vm_59050_hdfs____.ux1rrb/webapp
[junit4] 2> 2372549 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@solaris-vm:59050
[junit4] 2> 2372673 WARN (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2372675 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2372691 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_36551_datanode____i3o111/webapp
[junit4] 2> 2373210 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:36551
[junit4] 2> 2373298 WARN (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 2373301 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 2373329 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Extract jar:file:/export/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_64889_datanode____.t1997i/webapp
[junit4] 2> 2373380 INFO (IPC Server handler 3 on 59334) [ ] BlockStateChange BLOCK* processReport: from storage DS-83150989-fef9-491e-a45d-552f7376fbe7 node DatanodeRegistration(127.0.0.1:53870, datanodeUuid=242dac26-5978-4e47-9ac8-f9fad24f56e4, infoPort=33688, infoSecurePort=0, ipcPort=51356, storageInfo=lv=-56;cid=testClusterID;nsid=1758022918;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2373380 INFO (IPC Server handler 3 on 59334) [ ] BlockStateChange BLOCK* processReport: from storage DS-a5661e49-64e4-41ec-9be7-b1c866ca5dcc node DatanodeRegistration(127.0.0.1:53870, datanodeUuid=242dac26-5978-4e47-9ac8-f9fad24f56e4, infoPort=33688, infoSecurePort=0, ipcPort=51356, storageInfo=lv=-56;cid=testClusterID;nsid=1758022918;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2373857 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:64889
[junit4] 2> 2373957 INFO (IPC Server handler 4 on 59334) [ ] BlockStateChange BLOCK* processReport: from storage DS-43639fd4-2096-4e3f-a967-e9b085f082cb node DatanodeRegistration(127.0.0.1:34743, datanodeUuid=891799ae-95d4-4279-b8eb-a481696e3608, infoPort=39976, infoSecurePort=0, ipcPort=60133, storageInfo=lv=-56;cid=testClusterID;nsid=1758022918;c=0), blocks: 0, hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 2373957 INFO (IPC Server handler 4 on 59334) [ ] BlockStateChange BLOCK* processReport: from storage DS-dcd14bb8-feda-497b-b955-7790810cea17 node DatanodeRegistration(127.0.0.1:34743, datanodeUuid=891799ae-95d4-4279-b8eb-a481696e3608, infoPort=39976, infoSecurePort=0, ipcPort=60133, storageInfo=lv=-56;cid=testClusterID;nsid=1758022918;c=0), blocks: 0, hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 2374052 INFO (TEST-HdfsRecoveryZkTest.test-seed#[B6D9641594DB7180]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 2374054 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_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> 2374057 INFO (OverseerThreadFactory-9868-thread-1-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_solr ] o.a.s.c.CreateCollectionCmd Create collection recoverytest
[junit4] 2> 2374164 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_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> 2374165 INFO (qtp206177343-41551) [n:127.0.0.1:36924_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> 2374278 INFO (zkCallback-9295-thread-2-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_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> 2374279 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_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> 2375179 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2375179 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 2375279 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.s.IndexSchema [recoverytest_shard1_replica2] Schema name=minimal
[junit4] 2> 2375279 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.s.IndexSchema [recoverytest_shard1_replica1] Schema name=minimal
[junit4] 2> 2375281 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_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> 2375282 INFO (qtp206177343-41551) [n:127.0.0.1:36924_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> 2375283 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica1' using configuration from collection recoverytest
[junit4] 2> 2375283 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 x:recoverytest_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica2' using configuration from collection recoverytest
[junit4] 2> 2375291 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:59334/data
[junit4] 2> 2375291 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2375291 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.SolrCore [[recoverytest_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/tempDir-001/node2/recoverytest_shard1_replica1], dataDir=[hdfs://solaris-vm:59334/data/recoverytest/core_node2/data/]
[junit4] 2> 2375291 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node2/data/snapshot_metadata
[junit4] 2> 2375291 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://solaris-vm:59334/data
[junit4] 2> 2375291 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 2375291 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.SolrCore [[recoverytest_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_B6D9641594DB7180-001/tempDir-001/node1/recoverytest_shard1_replica2], dataDir=[hdfs://solaris-vm:59334/data/recoverytest/core_node1/data/]
[junit4] 2> 2375292 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node1/data/snapshot_metadata
[junit4] 2> 2375301 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2375301 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2375301 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2375304 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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> 2375304 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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> 2375304 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2375305 WARN (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2375308 WARN (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2380306 WARN (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2380309 WARN (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds and try again.
[junit4] 2> 2385314 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2385318 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2385318 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node2/data
[junit4] 2> 2385319 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node1/data
[junit4] 2> 2385348 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node2/data/index
[junit4] 2> 2385349 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://solaris-vm:59334/data/recoverytest/core_node1/data/index
[junit4] 2> 2385361 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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> 2385361 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2385362 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2385362 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2385362 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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> 2385362 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 2385373 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2385378 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 2385411 INFO (IPC Server handler 3 on 59334) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53870 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-43639fd4-2096-4e3f-a967-e9b085f082cb:NORMAL:127.0.0.1:34743|RBW], ReplicaUC[[DISK]DS-a5661e49-64e4-41ec-9be7-b1c866ca5dcc:NORMAL:127.0.0.1:53870|FINALIZED]]} size 0
[junit4] 2> 2385413 INFO (IPC Server handler 7 on 59334) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:34743 is added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-43639fd4-2096-4e3f-a967-e9b085f082cb:NORMAL:127.0.0.1:34743|RBW], ReplicaUC[[DISK]DS-a5661e49-64e4-41ec-9be7-b1c866ca5dcc:NORMAL:127.0.0.1:53870|FINALIZED]]} size 0
[junit4] 2> 2385424 INFO (IPC Server handler 1 on 59334) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:53870 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-dcd14bb8-feda-497b-b955-7790810cea17:NORMAL:127.0.0.1:34743|RBW], ReplicaUC[[DISK]DS-83150989-fef9-491e-a45d-552f7376fbe7:NORMAL:127.0.0.1:53870|FINALIZED]]} size 0
[junit4] 2> 2385424 INFO (IPC Server handler 0 on 59334) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:34743 is added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null, primaryNodeIndex=-1, replicas=[ReplicaUC[[DISK]DS-dcd14bb8-feda-497b-b955-7790810cea17:NORMAL:127.0.0.1:34743|RBW], ReplicaUC[[DISK]DS-83150989-fef9-491e-a45d-552f7376fbe7:NORMAL:127.0.0.1:53870|FINALIZED]]} size 0
[junit4] 2> 2385461 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2385461 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2385461 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2385471 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 2385472 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2385472 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 2385479 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2385479 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2385490 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2385490 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2385509 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6b8b536f[recoverytest_shard1_replica1] main]
[junit4] 2> 2385512 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2385513 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2385513 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2385513 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551222905091653632
[junit4] 2> 2385516 INFO (searcherExecutor-9873-thread-1-processing-n:127.0.0.1:40891_solr x:recoverytest_shard1_replica1 s:shard1 c:recoverytest r:core_node2) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.SolrCore [recoverytest_shard1_replica1] Registered new searcher Searcher@6b8b536f[recoverytest_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2385517 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@4f0b93fc[recoverytest_shard1_replica2] main]
[junit4] 2> 2385519 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2385519 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2385520 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2385520 INFO (searcherExecutor-9874-thread-1-processing-n:127.0.0.1:36924_solr x:recoverytest_shard1_replica2 s:shard1 c:recoverytest r:core_node1) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.c.SolrCore [recoverytest_shard1_replica2] Registered new searcher Searcher@4f0b93fc[recoverytest_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2385520 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1551222905098993664
[junit4] 2> 2385525 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2385527 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_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> 2385527 INFO (zkCallback-9295-thread-1-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_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> 2386028 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2386028 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2386028 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/
[junit4] 2> 2386028 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica1 url=http://127.0.0.1:40891/solr START replicas=[http://127.0.0.1:36924/solr/recoverytest_shard1_replica2/] nUpdates=100
[junit4] 2> 2386029 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=recoverytest_shard1_replica1 url=http://127.0.0.1:40891/solr DONE. We have no versions. sync failed.
[junit4] 2> 2386031 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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=1
[junit4] 2> 2386032 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2386032 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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> 2386041 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/ shard1
[junit4] 2> 2386147 INFO (zkCallback-9295-thread-3-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_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> 2386148 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_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> 2386193 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2386198 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 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=12039
[junit4] 2> 2386300 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_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> 2386301 INFO (zkCallback-9295-thread-3-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_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> 2386535 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 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=12375
[junit4] 2> 2386539 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_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> 2386639 INFO (zkCallback-9295-thread-3-processing-n:127.0.0.1:40891_solr) [n:127.0.0.1:40891_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> 2386639 INFO (zkCallback-9294-thread-1-processing-n:127.0.0.1:36924_solr) [n:127.0.0.1:36924_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> 2387540 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_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=13492
[junit4] 2> 2387542 INFO (TEST-HdfsRecoveryZkTest.test-seed#[B6D9641594DB7180]) [ ] o.a.s.c.RecoveryZkTest Indexing 1200 documents
[junit4] 2> 2387568 DEBUG (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.HdfsTransactionLog Opening new tlog hdfs tlog{file=hdfs://solaris-vm:59334/data/recoverytest/core_node2/data/tlog/tlog.0000000000000000000 refcount=1}
[junit4] 2> 2387625 DEBUG (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.HdfsTransactionLog Opening new tlog hdfs tlog{file=hdfs://solaris-vm:59334/data/recoverytest/core_node1/data/tlog/tlog.0000000000000000000 refcount=1}
[junit4] 2> 2387638 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-0 (1551222907240185856)]} 0 57
[junit4] 2> 2387638 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0 (1551222907240185856)]} 0 76
[junit4] 2> 2387639 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-0 (1551222907224457216)]} 0 58
[junit4] 2> 2387640 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0 (1551222907224457216)]} 0 92
[junit4] 2> 2387642 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-1 (1551222907320926208)]} 0 1
[junit4] 2> 2387643 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1 (1551222907320926208)]} 0 3
[junit4] 2> 2387643 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-1 (1551222907323023360)]} 0 1
[junit4] 2> 2387643 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1 (1551222907323023360)]} 0 2
[junit4] 2> 2387646 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-0 (-1551222907326169088)]} 0 1
[junit4] 2> 2387646 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-0 (-1551222907325120512)]} 0 2
[junit4] 2> 2387647 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-0 (-1551222907326169088)]} 0 2
[junit4] 2> 2387647 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-0 (-1551222907325120512)]} 0 3
[junit4] 2> 2387649 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-2 (1551222907330363393)]} 0 1
[junit4] 2> 2387649 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2 (1551222907330363393)]} 0 1
[junit4] 2> 2387650 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-2 (1551222907330363392)]} 0 1
[junit4] 2> 2387650 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2 (1551222907330363392)]} 0 2
[junit4] 2> 2387652 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-3 (1551222907332460544)]} 0 1
[junit4] 2> 2387652 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3 (1551222907332460544)]} 0 1
[junit4] 2> 2387652 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-3 (1551222907333509120)]} 0 1
[junit4] 2> 2387653 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3 (1551222907333509120)]} 0 1
[junit4] 2> 2387655 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-4 (1551222907335606273)]} 0 1
[junit4] 2> 2387656 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4 (1551222907335606273)]} 0 2
[junit4] 2> 2387657 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-4 (1551222907335606272)]} 0 3
[junit4] 2> 2387658 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-1 (-1551222907338752000)]} 0 1
[junit4] 2> 2387658 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-1 (-1551222907338752000)]} 0 2
[junit4] 2> 2387660 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-5 (1551222907341897728)]} 0 0
[junit4] 2> 2387660 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5 (1551222907341897728)]} 0 1
[junit4] 2> 2387662 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-2 (-1551222907343994880)]} 0 0
[junit4] 2> 2387662 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-2 (-1551222907343994880)]} 0 1
[junit4] 2> 2387664 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-6 (1551222907346092032)]} 0 0
[junit4] 2> 2387664 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6 (1551222907346092032)]} 0 1
[junit4] 2> 2387666 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-7 (1551222907348189184)]} 0 0
[junit4] 2> 2387666 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7 (1551222907348189184)]} 0 1
[junit4] 2> 2387668 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-7 (-1551222907350286336)]} 0 0
[junit4] 2> 2387668 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-7 (-1551222907350286336)]} 0 1
[junit4] 2> 2387669 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-8 (1551222907351334912)]} 0 0
[junit4] 2> 2387670 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8 (1551222907351334912)]} 0 1
[junit4] 2> 2387671 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4 (1551222907335606272)]} 0 18
[junit4] 2> 2387672 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-9 (1551222907354480640)]} 0 0
[junit4] 2> 2387672 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9 (1551222907354480640)]} 0 1
[junit4] 2> 2387675 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-10 (1551222907356577792)]} 0 0
[junit4] 2> 2387675 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10 (1551222907356577792)]} 0 2
[junit4] 2> 2387676 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-1 (-1551222907358674944)]} 0 0
[junit4] 2> 2387676 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-1 (-1551222907358674944)]} 0 1
[junit4] 2> 2387678 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-5 (1551222907360772096)]} 0 0
[junit4] 2> 2387679 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5 (1551222907360772096)]} 0 1
[junit4] 2> 2387680 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-11 (1551222907362869248)]} 0 1
[junit4] 2> 2387680 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11 (1551222907362869248)]} 0 1
[junit4] 2> 2387682 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-2 (-1551222907363917824)]} 0 1
[junit4] 2> 2387683 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-2 (-1551222907363917824)]} 0 2
[junit4] 2> 2387684 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-11 (-1551222907364966400)]} 0 1
[junit4] 2> 2387684 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-11 (-1551222907364966400)]} 0 2
[junit4] 2> 2387688 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-12 (1551222907369160704)]} 0 2
[junit4] 2> 2387688 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-12 (1551222907369160704)]} 0 3
[junit4] 2> 2387692 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-6 (1551222907369160705)]} 0 6
[junit4] 2> 2387693 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-13 (1551222907373355008)]} 0 3
[junit4] 2> 2387693 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-13 (1551222907373355008)]} 0 4
[junit4] 2> 2387695 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6 (1551222907369160705)]} 0 9
[junit4] 2> 2387696 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-13 (-1551222907378597888)]} 0 1
[junit4] 2> 2387696 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-13 (-1551222907378597888)]} 0 2
[junit4] 2> 2387699 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-14 (1551222907381743616)]} 0 1
[junit4] 2> 2387699 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-14 (1551222907381743616)]} 0 2
[junit4] 2> 2387701 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-7 (1551222907380695040)]} 0 3
[junit4] 2> 2387702 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7 (1551222907380695040)]} 0 5
[junit4] 2> 2387702 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-14 (-1551222907384889344)]} 0 2
[junit4] 2> 2387703 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-14 (-1551222907384889344)]} 0 2
[junit4] 2> 2387705 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-15 (1551222907388035072)]} 0 1
[junit4] 2> 2387706 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-15 (1551222907388035072)]} 0 2
[junit4] 2> 2387708 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-7 (-1551222907389083648)]} 0 3
[junit4] 2> 2387708 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-7 (-1551222907389083648)]} 0 4
[junit4] 2> 2387709 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-16 (1551222907391180800)]} 0 1
[junit4] 2> 2387709 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-16 (1551222907391180800)]} 0 2
[junit4] 2> 2387712 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-17 (1551222907395375104)]} 0 1
[junit4] 2> 2387712 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-17 (1551222907395375104)]} 0 2
[junit4] 2> 2387714 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-8 (1551222907396423680)]} 0 2
[junit4] 2> 2387714 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8 (1551222907396423680)]} 0 3
[junit4] 2> 2387717 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-15 (-1551222907398520832)]} 0 3
[junit4] 2> 2387717 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-15 (-1551222907398520832)]} 0 4
[junit4] 2> 2387717 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-9 (1551222907400617984)]} 0 1
[junit4] 2> 2387718 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9 (1551222907400617984)]} 0 2
[junit4] 2> 2387720 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-10 (1551222907403763712)]} 0 1
[junit4] 2> 2387721 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10 (1551222907403763712)]} 0 2
[junit4] 2> 2387722 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-18 (1551222907404812288)]} 0 2
[junit4] 2> 2387723 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-18 (1551222907404812288)]} 0 3
[junit4] 2> 2387724 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-11 (1551222907407958016)]} 0 2
[junit4] 2> 2387725 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11 (1551222907407958016)]} 0 2
[junit4] 2> 2387726 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-17 (-1551222907409006592)]} 0 2
[junit4] 2> 2387726 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-17 (-1551222907409006592)]} 0 2
[junit4] 2> 2387729 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-11 (-1551222907413200897)]} 0 1
[junit4] 2> 2387730 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-11 (-1551222907413200897)]} 0 2
[junit4] 2> 2387730 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-19 (1551222907413200896)]} 0 3
[junit4] 2> 2387730 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-19 (1551222907413200896)]} 0 3
[junit4] 2> 2387733 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-18 (-1551222907417395201)]} 0 1
[junit4] 2> 2387733 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-18 (-1551222907417395201)]} 0 2
[junit4] 2> 2387734 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-12 (1551222907417395200)]} 0 2
[junit4] 2> 2387734 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-12 (1551222907417395200)]} 0 3
[junit4] 2> 2387736 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-20 (1551222907420540928)]} 0 1
[junit4] 2> 2387736 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-20 (1551222907420540928)]} 0 2
[junit4] 2> 2387737 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-13 (1551222907421589504)]} 0 1
[junit4] 2> 2387738 INFO (qtp1052707760-41564) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-13 (1551222907421589504)]} 0 2
[junit4] 2> 2387739 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-21 (1551222907423686656)]} 0 1
[junit4] 2> 2387740 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-21 (1551222907423686656)]} 0 2
[junit4] 2> 2387741 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-13 (-1551222907424735232)]} 0 1
[junit4] 2> 2387741 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-13 (-1551222907424735232)]} 0 2
[junit4] 2> 2387743 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-22 (1551222907427880960)]} 0 1
[junit4] 2> 2387743 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-22 (1551222907427880960)]} 0 2
[junit4] 2> 2387744 INFO (qtp206177343-41552) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-14 (1551222907428929536)]} 0 1
[junit4] 2> 2387744 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-14 (1551222907428929536)]} 0 2
[junit4] 2> 2387747 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-23 (1551222907431026688)]} 0 2
[junit4] 2> 2387747 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-23 (1551222907431026688)]} 0 3
[junit4] 2> 2387749 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-14 (-1551222907432075264)]} 0 3
[junit4] 2> 2387749 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-14 (-1551222907432075264)]} 0 3
[junit4] 2> 2387752 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-24 (1551222907435220992)]} 0 3
[junit4] 2> 2387752 INFO (qtp206177343-41555) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-15 (1551222907437318144)]} 0 2
[junit4] 2> 2387753 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-15 (1551222907437318144)]} 0 3
[junit4] 2> 2387753 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-24 (1551222907435220992)]} 0 5
[junit4] 2> 2387757 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-16 (1551222907441512448)]} 0 2
[junit4] 2> 2387757 INFO (qtp1052707760-41560) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-16 (1551222907441512448)]} 0 3
[junit4] 2> 2387758 INFO (qtp206177343-41558) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-25 (1551222907442561024)]} 0 2
[junit4] 2> 2387758 INFO (qtp1052707760-41562) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-25 (1551222907442561024)]} 0 3
[junit4] 2> 2387761 INFO (qtp206177343-41551) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[2-20 (-1551222907446755328)]} 0 1
[junit4] 2> 2387761 INFO (qtp1052707760-41565) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-20 (-1551222907446755328)]} 0 2
[junit4] 2> 2387764 INFO (qtp206177343-41554) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[1-17 (1551222907447803904)]} 0 3
[junit4] 2> 2387764 INFO (qtp1052707760-41561) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-17 (1551222907447803904)]} 0 4
[junit4] 2> 2387766 INFO (qtp206177343-41556) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{add=[2-26 (1551222907449901056)]} 0 3
[junit4] 2> 2387767 INFO (qtp1052707760-41553) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-26 (1551222907449901056)]} 0 4
[junit4] 2> 2387769 INFO (qtp206177343-41549) [n:127.0.0.1:36924_solr c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:40891/solr/recoverytest_shard1_replica1/&wt=javabin&version=2}{delete=[1-15 (-1551222907453046784)]} 0 3
[junit4] 2> 2387769 INFO (qtp1052707760-41563) [n:127.0.0.1:40891_solr c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica1] webapp=/solr path=/update params=
[...truncated too long message...]
ockManager.getTotalBlocks(BlockManager.java:3370)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:5729)
[junit4] 2> ... 54 more
[junit4] 2> 2405890 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34846 34846
[junit4] 2> 2405891 INFO (SUITE-HdfsRecoveryZkTest-seed#[B6D9641594DB7180]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {rnd_b=PostingsFormat(name=LuceneVarGapFixedInterval), _version_=FSTOrd50, a_t=Lucene50(blocksize=128), a_i=PostingsFormat(name=LuceneVarGapFixedInterval), id=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{}, maxPointsInLeafNode=1351, maxMBSortInHeap=5.558411861102829, sim=RandomSimilarity(queryNorm=true): {}, locale=be-BY, timezone=America/Indiana/Winamac
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=2,free=199765512,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [SuggesterWFSTTest, TestNumericTerms64, LoggingHandlerTest, TestManagedSchemaThreadSafety, TestReRankQParserPlugin, FileBasedSpellCheckerTest, BooleanFieldTest, TestGeoJSONResponseWriter, TestMissingGroups, EnumFieldTest, FieldAnalysisRequestHandlerTest, MinimalSchemaTest, HdfsRestartWhileUpdatingTest, TestManagedResource, DateRangeFieldTest, TestObjectReleaseTracker, ConvertedLegacyTest, SignatureUpdateProcessorFactoryTest, TestSubQueryTransformerCrossCore, TestOrdValues, EchoParamsTest, TestRandomFaceting, ExplicitHLLTest, TestDocTermOrds, TestCloudManagedSchema, TestOverriddenPrefixQueryForCustomFieldType, TestSolrCoreProperties, AliasIntegrationTest, ResponseHeaderTest, TestSolrIndexConfig, CloudMLTQParserTest, ResponseLogComponentTest, UUIDUpdateProcessorFallbackTest, TestJoin, TestFieldCacheVsDocValues, BlockDirectoryTest, TestCorePropertiesReload, TestSolrDynamicMBean, RegexBoostProcessorTest, TestLMJelinekMercerSimilarityFactory, SolrXmlInZkTest, SpellingQueryConverterTest, TestQueryUtils, TestSolrCloudSnapshots, TestRandomCollapseQParserPlugin, TestStressRecovery, TestRecovery, SolrIndexSplitterTest, BlockJoinFacetRandomTest, TestPKIAuthenticationPlugin, SpellCheckComponentTest, URLClassifyProcessorTest, HdfsThreadLeakTest, TestCustomSort, TestReplicationHandlerBackup, TestCollapseQParserPlugin, DistributedFacetPivotLongTailTest, TestValueSourceCache, TestFoldingMultitermQuery, TestNRTOpen, TestShardHandlerFactory, CircularListTest, TestWriterPerf, ConfigSetsAPITest, TestDocSet, TestJmxMonitoredMap, BJQParserTest, ZkSolrClientTest, TestRestoreCore, AsyncCallRequestStatusResponseTest, TestSolr4Spatial2, DistributedFacetPivotSmallTest, NotRequiredUniqueKeyTest, TestCoreDiscovery, TestPushWriter, TestOnReconnectListenerSupport, CoreSorterTest, TestCloudDeleteByQuery, HdfsDirectoryTest, TestSolrCloudWithSecureImpersonation, TestJsonFacets, TestDistributedGrouping, TestSolrDeletionPolicy2, TestUtils, TestExceedMaxTermLength, BadComponentTest, TestSolrCLIRunExample, SolrCLIZkUtilsTest, SmileWriterTest, TestStandardQParsers, HdfsCollectionsAPIDistributedZkTest, TestTrie, TestConfigSetProperties, TestReplicaProperties, DistanceFunctionTest, ReplaceNodeTest, QueryResultKeyTest, TestCloudPivotFacet, TestStressLiveNodes, TermVectorComponentTest, CursorMarkTest, TestCollectionAPI, RequestHandlersTest, UUIDFieldTest, TestReloadDeadlock, CloneFieldUpdateProcessorFactoryTest, CollectionReloadTest, HighlighterConfigTest, TestChildDocTransformer, TestBadConfig, SolrInfoMBeanTest, DeleteShardTest, PreAnalyzedFieldTest, BasicDistributedZk2Test, BadIndexSchemaTest, SolrCmdDistributorTest, TestAnalyzedSuggestions, HttpPartitionTest, IndexSchemaTest, ExternalFileFieldSortTest, StatsComponentTest, TestFastWriter, SpatialRPTFieldTypeTest, TestQuerySenderListener, ShardRoutingCustomTest, TestRangeQuery, AtomicUpdatesTest, RestartWhileUpdatingTest, AddBlockUpdateTest, LeaderInitiatedRecoveryOnCommitTest, RankQueryTest, DeleteInactiveReplicaTest, GraphQueryTest, TermVectorComponentDistributedTest, TestDynamicFieldResource, CreateCollectionCleanupTest, TestLegacyNumericRangeQueryBuilder, CurrencyFieldOpenExchangeTest, SuggestComponentTest, SpellPossibilityIteratorTest, TestRawTransformer, ExitableDirectoryReaderTest, TestUniqueKeyFieldResource, TestDFRSimilarityFactory, JsonLoaderTest, TestClassicSimilarityFactory, TestSimpleQParserPlugin, TestQueryTypes, TestFieldTypeResource, RAMDirectoryFactoryTest, TestXmlQParserPlugin, TestSha256AuthenticationProvider, OverseerTaskQueueTest, AnalyticsMergeStrategyTest, TestExactStatsCache, ResourceLoaderTest, TestSystemIdResolver, SSLMigrationTest, SuggesterTSTTest, TestAddFieldRealTimeGet, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestZkChroot, AutoCommitTest, TestStressReorder, TestStressVersions, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, TestSort, TestFunctionQuery, TestLazyCores, HighlighterTest, CurrencyFieldXmlFileTest, TestExtendedDismaxParser, SuggesterFSTTest, SolrRequestParserTest, SuggesterTest, TestCSVLoader, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, TestUpdate, TestAtomicUpdateErrorCases, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DebugComponentTest, CacheHeaderTest, TestSurroundQueryParser, LukeRequestHandlerTest, TestOmitPositions, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, TestSolrQueryParser, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, TestPHPSerializedResponseWriter, TestComponentsName, TestLFUCache, TestSuggestSpellingConverter, DOMUtilTest, ClusterStateTest, TestSolrJ, TestLRUCache, ZkNodePropsTest, SliceStateTest, SystemInfoHandlerTest, FileUtilsTest, DistributedMLTComponentTest, CursorPagingTest, DistributedIntervalFacetingTest, TestCrossCoreJoin, TestDistributedMissingSort, TestSimpleTrackingShardHandler, TestEmbeddedSolrServerConstructors, ConnectionReuseTest, ActionThrottleTest, CdcrReplicationDistributedZkTest, CdcrReplicationHandlerTest, CdcrRequestHandlerTest, CdcrVersionReplicationTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionStateFormat2Test, CollectionTooManyReplicasTest, CollectionsAPISolrJTest, DeleteNodeTest, DistribJoinFromCollectionTest, DistributedQueueTest, ForceLeaderTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverriddenZkACLAndCredentialsProvidersTest, OverseerCollectionConfigSetProcessorTest, OverseerStatusTest, RecoveryAfterSoftCommitTest, SharedFSAutoReplicaFailoverTest, SharedFSAutoReplicaFailoverUtilsTest, TestAuthenticationFramework, TestCloudPseudoReturnFields, TestCloudRecovery, TestConfigSetsAPI, TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestCryptoKeys, TestDeleteCollectionOnDownNodes, TestDistribDocBasedVersion, TestDownShardTolerantSearch, TestExclusionRuleCollectionAccess, TestHdfsCloudBackupRestore, TestLeaderElectionWithEmptyReplica, TestLeaderElectionZkExpiry, TestLeaderInitiatedRecoveryThread, TestRandomRequestDistribution, TestRequestForwarding, TestRequestStatusCollectionAPI, TestSolrCloudWithDelegationTokens, TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorRandomCloud, HdfsBasicDistributedZk2Test, HdfsChaosMonkeyNothingIsSafeTest, HdfsChaosMonkeySafeLeaderTest, HdfsNNFailoverTest, HdfsRecoveryZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HdfsRecoveryZkTest -Dtests.seed=B6D9641594DB7180 -Dtests.slow=true -Dtests.locale=be-BY -Dtests.timezone=America/Indiana/Winamac -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[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
[junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:43)
[junit4] > at org.apache.solr.update.HdfsTransactionLog.<init>(HdfsTransactionLog.java:130)
[junit4] > at org.apache.solr.update.HdfsUpdateLog.init(HdfsUpdateLog.java:202)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:137)
[junit4] > at org.apache.solr.update.UpdateHandler.<init>(UpdateHandler.java:94)
[junit4] > at org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:102)
[junit4] > at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[junit4] > at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:723)
[junit4] > at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:785)
[junit4] > at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1024)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:889)
[junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:793)
[junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:868)
[junit4] > at org.apache.solr.core.CoreContainer.lambda$load$0(CoreContainer.java:517)
[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([B6D9641594DB7180]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:260)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [526/652 (1!)] on J1 in 65.75s, 1 test, 1 failure <<< FAILURES!
[...truncated 62725 lines...]