Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/1866/
1 tests failed.
FAILED: org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest.test
Error Message:
Mismatch in counts between replicas
Stack Trace:
java.lang.AssertionError: Mismatch in counts between replicas
at
__randomizedtesting.SeedInfo.seed([D7D9D787996D02BF:5F8DE85D37916F47]:0)
at org.junit.Assert.fail(Assert.java:93)
at
org.apache.solr.cloud.RecoveryZkTest.assertShardConsistency(RecoveryZkTest.java:143)
at org.apache.solr.cloud.RecoveryZkTest.test(RecoveryZkTest.java:126)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11544 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest
[junit4] 2> Creating dataDir:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/init-core-data-001
[junit4] 2> 527270 WARN
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=9 numCloses=9
[junit4] 2> 527270 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 527271 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 527272 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-001
[junit4] 2> 527272 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 527281 INFO (Thread-3074) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 527281 INFO (Thread-3074) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 527315 ERROR (Thread-3074) [ ] o.a.z.s.ZooKeeperServer
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action
on ERROR or SHUTDOWN server state changes
[junit4] 2> 527381 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:34057
[junit4] 2> 527435 INFO (jetty-launcher-1349-thread-1) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 527442 INFO (jetty-launcher-1349-thread-2) [ ]
o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 527578 INFO (jetty-launcher-1349-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@4df07287{/solr,null,AVAILABLE}
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@2974f312{HTTP/1.1,[http/1.1]}{127.0.0.1:53762}
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.e.j.s.Server Started @530932ms
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53762}
[junit4] 2> 527579 ERROR (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.0
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 527579 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-06-15T20:25:01.064Z
[junit4] 2> 527661 INFO (jetty-launcher-1349-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6c0d1d04{/solr,null,AVAILABLE}
[junit4] 2> 527661 INFO (jetty-launcher-1349-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@7df89456{HTTP/1.1,[http/1.1]}{127.0.0.1:53723}
[junit4] 2> 527661 INFO (jetty-launcher-1349-thread-2) [ ]
o.e.j.s.Server Started @531014ms
[junit4] 2> 527661 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53723}
[junit4] 2> 527662 ERROR (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 527662 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.0.0
[junit4] 2> 527662 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 527662 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 527662 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-06-15T20:25:01.147Z
[junit4] 2> 527715 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 527741 INFO (jetty-launcher-1349-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34057/solr
[junit4] 2> 527742 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 527779 INFO (jetty-launcher-1349-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34057/solr
[junit4] 2> 527928 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 527929 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53723_solr
[junit4] 2> 527930 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.c.Overseer Overseer
(id=98143980799590405-127.0.0.1:53723_solr-n_0000000000) starting
[junit4] 2> 527938 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 527940 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53762_solr
[junit4] 2> 527956 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 527974 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 528031 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53723_solr
[junit4] 2> 528047 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 528050 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 528310 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53762.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528323 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53762.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528324 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53762.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528325 INFO (jetty-launcher-1349-thread-1)
[n:127.0.0.1:53762_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-001/node1/.
[junit4] 2> 528435 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53723.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528448 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53723.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528448 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53723.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 528449 INFO (jetty-launcher-1349-thread-2)
[n:127.0.0.1:53723_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-001/node2/.
[junit4] 2> 528835 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 528837 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34057/solr ready
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 528988 WARN
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.h.m.i.MetricsConfig Cannot locate configuration: tried
hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 529063 WARN
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 529066 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
jetty-6.1.26
[junit4] 2> 529126 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Extract
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/hdfs
to ./temp/Jetty_localhost_56976_hdfs____94o8jl/webapp
[junit4] 2> 530004 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:56976
[junit4] 2> 530554 WARN
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 530556 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
jetty-6.1.26
[junit4] 2> 530638 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Extract
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
to ./temp/Jetty_localhost_40011_datanode____.2nkcl/webapp
[junit4] 2> 531527 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:40011
[junit4] 2> 532080 WARN
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 532082 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
jetty-6.1.26
[junit4] 2> 532129 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Extract
jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.7.2-tests.jar!/webapps/datanode
to ./temp/Jetty_localhost_56403_datanode____.zxr8j/webapp
[junit4] 2> 532207 INFO (IPC Server handler 3 on 42793) [ ]
BlockStateChange BLOCK* processReport: from storage
DS-2c993717-5ef6-4ff2-9074-e1625ae22445 node
DatanodeRegistration(127.0.0.1:50646,
datanodeUuid=e55bf0f5-aee8-4ef5-9fd9-ea892400800c, infoPort=54680,
infoSecurePort=0, ipcPort=33458,
storageInfo=lv=-56;cid=testClusterID;nsid=885877053;c=0), blocks: 0,
hasStaleStorage: true, processing time: 0 msecs
[junit4] 2> 532208 INFO (IPC Server handler 3 on 42793) [ ]
BlockStateChange BLOCK* processReport: from storage
DS-2db6ce5b-6cce-4113-8131-78eae7e328c1 node
DatanodeRegistration(127.0.0.1:50646,
datanodeUuid=e55bf0f5-aee8-4ef5-9fd9-ea892400800c, infoPort=54680,
infoSecurePort=0, ipcPort=33458,
storageInfo=lv=-56;cid=testClusterID;nsid=885877053;c=0), blocks: 0,
hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 532714 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:56403
[junit4] 2> 533162 INFO (IPC Server handler 7 on 42793) [ ]
BlockStateChange BLOCK* processReport: from storage
DS-3aaceb91-4a16-4938-a5ed-ea62a0dfa977 node
DatanodeRegistration(127.0.0.1:48087,
datanodeUuid=2f2e2f8e-e828-47c5-b646-26712f2a23ce, infoPort=43739,
infoSecurePort=0, ipcPort=38098,
storageInfo=lv=-56;cid=testClusterID;nsid=885877053;c=0), blocks: 0,
hasStaleStorage: true, processing time: 10 msecs
[junit4] 2> 533162 INFO (IPC Server handler 7 on 42793) [ ]
BlockStateChange BLOCK* processReport: from storage
DS-40fb61b1-05ab-4556-b4c7-08463e0cbdfb node
DatanodeRegistration(127.0.0.1:48087,
datanodeUuid=2f2e2f8e-e828-47c5-b646-26712f2a23ce, infoPort=43739,
infoSecurePort=0, ipcPort=38098,
storageInfo=lv=-56;cid=testClusterID;nsid=885877053;c=0), blocks: 0,
hasStaleStorage: false, processing time: 0 msecs
[junit4] 2> 533632 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 533656 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 533669 INFO
(OverseerThreadFactory-3149-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_solr ] o.a.s.c.CreateCollectionCmd Create collection
recoverytest
[junit4] 2> 533806 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica_n1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 533806 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 533842 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr ]
o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica_n2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 533843 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 533952 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_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> 533952 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_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> 534839 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 7.0.0
[junit4] 2> 534848 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.s.IndexSchema
[recoverytest_shard1_replica_n1] Schema name=minimal
[junit4] 2> 534851 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 534851 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica_n1' using
configuration from collection recoverytest, trusted=true
[junit4] 2> 534852 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53723.solr.core.recoverytest.shard1.replica_n1' (registry
'solr.core.recoverytest.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 534858 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:42793/data
[junit4] 2> 534858 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 534858 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 534858 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.c.SolrCore
[[recoverytest_shard1_replica_n1] ] Opening new SolrCore at
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-001/node2/recoverytest_shard1_replica_n1],
dataDir=[hdfs://localhost:42793/data/recoverytest/core_node1/data/]
[junit4] 2> 534860 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node1/data/snapshot_metadata
[junit4] 2> 534865 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 7.0.0
[junit4] 2> 534869 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct
memory allocation set to [true]
[junit4] 2> 534869 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of
[16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 534874 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.s.IndexSchema
[recoverytest_shard1_replica_n2] Schema name=minimal
[junit4] 2> 534888 WARN (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds
and try again.
[junit4] 2> 534891 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.s.IndexSchema
Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 534891 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.CoreContainer Creating SolrCore 'recoverytest_shard1_replica_n2' using
configuration from collection recoverytest, trusted=true
[junit4] 2> 534894 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_53762.solr.core.recoverytest.shard1.replica_n2' (registry
'solr.core.recoverytest.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@6c1d8971
[junit4] 2> 534894 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:42793/data
[junit4] 2> 534894 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 534894 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.SolrCore
solr.RecoveryStrategy.Builder
[junit4] 2> 534894 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.SolrCore
[[recoverytest_shard1_replica_n2] ] Opening new SolrCore at
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-001/node1/recoverytest_shard1_replica_n2],
dataDir=[hdfs://localhost:42793/data/recoverytest/core_node2/data/]
[junit4] 2> 534896 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node2/data/snapshot_metadata
[junit4] 2> 534906 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct
memory allocation set to [true]
[junit4] 2> 534906 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of
[16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 534909 WARN (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds
and try again.
[junit4] 2> 539976 WARN (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds
and try again.
[junit4] 2> 540015 WARN (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.s.h.HdfsDirectory The NameNode is in SafeMode - Solr will wait 5 seconds
and try again.
[junit4] 2> 545702 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 545705 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 545706 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node2/data
[junit4] 2> 545712 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node1/data
[junit4] 2> 545774 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node1/data/index
[junit4] 2> 545779 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory creating directory factory for path
hdfs://localhost:42793/data/recoverytest/core_node2/data/index
[junit4] 2> 545786 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct
memory allocation set to [true]
[junit4] 2> 545786 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of
[16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 545801 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct
memory allocation set to [true]
[junit4] 2> 545801 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of
[16777216] will allocate [1] slabs and use ~[16777216] bytes
[junit4] 2> 545810 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 545831 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 546266 INFO (IPC Server handler 7 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48087 is
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-2c993717-5ef6-4ff2-9074-e1625ae22445:NORMAL:127.0.0.1:50646|RBW],
ReplicaUC[[DISK]DS-3aaceb91-4a16-4938-a5ed-ea62a0dfa977:NORMAL:127.0.0.1:48087|RBW]]}
size 0
[junit4] 2> 546278 INFO (IPC Server handler 5 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50646 is
added to blk_1073741826_1002{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-3aaceb91-4a16-4938-a5ed-ea62a0dfa977:NORMAL:127.0.0.1:48087|RBW],
ReplicaUC[[DISK]DS-2db6ce5b-6cce-4113-8131-78eae7e328c1:NORMAL:127.0.0.1:50646|FINALIZED]]}
size 0
[junit4] 2> 546286 INFO (IPC Server handler 0 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48087 is
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-2c993717-5ef6-4ff2-9074-e1625ae22445:NORMAL:127.0.0.1:50646|RBW],
ReplicaUC[[DISK]DS-40fb61b1-05ab-4556-b4c7-08463e0cbdfb:NORMAL:127.0.0.1:48087|RBW]]}
size 0
[junit4] 2> 546295 INFO (IPC Server handler 4 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50646 is
added to blk_1073741825_1001{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-2c993717-5ef6-4ff2-9074-e1625ae22445:NORMAL:127.0.0.1:50646|RBW],
ReplicaUC[[DISK]DS-40fb61b1-05ab-4556-b4c7-08463e0cbdfb:NORMAL:127.0.0.1:48087|RBW]]}
size 0
[junit4] 2> 546486 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 546486 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 546486 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 546507 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 546507 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 546552 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 546552 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 546553 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.u.HdfsUpdateLog Initializing HdfsUpdateLog: tlogDfsReplication=3
[junit4] 2> 546588 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 546588 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 546598 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@3c2ffcc8[recoverytest_shard1_replica_n2] main]
[junit4] 2> 546601 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf
[junit4] 2> 546602 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 546602 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 546605 INFO
(searcherExecutor-3155-thread-1-processing-n:127.0.0.1:53762_solr
x:recoverytest_shard1_replica_n2 s:shard1 c:recoverytest)
[n:127.0.0.1:53762_solr c:recoverytest s:shard1
x:recoverytest_shard1_replica_n2] o.a.s.c.SolrCore
[recoverytest_shard1_replica_n2] Registered new searcher
Searcher@3c2ffcc8[recoverytest_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 546605 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1570303713046691840
[junit4] 2> 546611 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for
shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 546615 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_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> 546616 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_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> 546646 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@26e0a489[recoverytest_shard1_replica_n1] main]
[junit4] 2> 546648 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf
[junit4] 2> 546648 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 546649 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 546650 INFO
(searcherExecutor-3154-thread-1-processing-n:127.0.0.1:53723_solr
x:recoverytest_shard1_replica_n1 s:shard1 c:recoverytest)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1
x:recoverytest_shard1_replica_n1] o.a.s.c.SolrCore
[recoverytest_shard1_replica_n1] Registered new searcher
Searcher@26e0a489[recoverytest_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 546650 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.u.UpdateLog
Could not find max version in index or recent updates, using new clock
1570303713093877760
[junit4] 2> 547112 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 547112 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 547112 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.SyncStrategy
Sync replicas to http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/
[junit4] 2> 547113 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.u.PeerSync
PeerSync: core=recoverytest_shard1_replica_n2 url=http://127.0.0.1:53762/solr
START replicas=[http://127.0.0.1:53723/solr/recoverytest_shard1_replica_n1/]
nUpdates=100
[junit4] 2> 547122 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.u.PeerSync
PeerSync: core=recoverytest_shard1_replica_n2 url=http://127.0.0.1:53762/solr
DONE. We have no versions. sync failed.
[junit4] 2> 547126 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.c.S.Request [recoverytest_shard1_replica_n1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=1
[junit4] 2> 547127 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.SyncStrategy
Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 547127 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
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> 547127 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 547131 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/ shard1
[junit4] 2> 547240 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_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> 547240 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_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> 547282 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.c.ZkController
I am the leader, no recovery necessary
[junit4] 2> 547287 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n2] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica_n2&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=13444
[junit4] 2> 547391 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_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> 547392 INFO
(zkCallback-1360-thread-1-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_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> 547661 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 x:recoverytest_shard1_replica_n1] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=recoverytest_shard1_replica_n1&action=CREATE&numShards=1&collection=recoverytest&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=13856
[junit4] 2> 547675 INFO (qtp804007706-8304) [n:127.0.0.1:53723_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> 547683 INFO
(OverseerCollectionConfigSetProcessor-98143980799590405-127.0.0.1:53723_solr-n_0000000000)
[n:127.0.0.1:53723_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 547774 INFO
(zkCallback-1361-thread-1-processing-n:127.0.0.1:53762_solr)
[n:127.0.0.1:53762_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> 547774 INFO
(zkCallback-1360-thread-3-processing-n:127.0.0.1:53723_solr)
[n:127.0.0.1:53723_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> 548676 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=1&name=recoverytest&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2}
status=0 QTime=15020
[junit4] 2> 548704 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.c.RecoveryZkTest Indexing 700 documents
[junit4] 2> 548735 DEBUG (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.HdfsTransactionLog Opening new tlog hdfs
tlog{file=hdfs://localhost:42793/data/recoverytest/core_node2/data/tlog/tlog.0000000000000000000
refcount=1}
[junit4] 2> 548774 DEBUG (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.HdfsTransactionLog Opening new tlog hdfs
tlog{file=hdfs://localhost:42793/data/recoverytest/core_node1/data/tlog/tlog.0000000000000000000
refcount=1}
[junit4] 2> 548805 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-0
(1570303715268624384)]} 0 43
[junit4] 2> 548807 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-0
(1570303715268624384)]} 0 83
[junit4] 2> 548807 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-0
(1570303715259187200)]} 0 57
[junit4] 2> 548807 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-0
(1570303715259187200)]} 0 92
[junit4] 2> 548822 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-0
(-1570303715357753344)]} 0 11
[junit4] 2> 548822 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-0
(-1570303715356704768)]} 0 12
[junit4] 2> 548822 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-0
(-1570303715357753344)]} 0 13
[junit4] 2> 548823 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-0
(-1570303715356704768)]} 0 14
[junit4] 2> 548826 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-1
(1570303715372433408)]} 0 1
[junit4] 2> 548826 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-1
(1570303715372433408)]} 0 2
[junit4] 2> 548827 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-1
(1570303715373481984)]} 0 2
[junit4] 2> 548828 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-1
(1570303715373481984)]} 0 4
[junit4] 2> 548829 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-2
(1570303715376627712)]} 0 1
[junit4] 2> 548829 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-2
(1570303715376627712)]} 0 2
[junit4] 2> 548830 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-2
(1570303715377676288)]} 0 1
[junit4] 2> 548831 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-2
(1570303715377676288)]} 0 2
[junit4] 2> 548831 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-3
(1570303715379773440)]} 0 0
[junit4] 2> 548831 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-3
(1570303715379773440)]} 0 1
[junit4] 2> 548834 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-3
(1570303715380822016)]} 0 1
[junit4] 2> 548834 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-3
(1570303715380822016)]} 0 2
[junit4] 2> 548834 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-2
(-1570303715382919168)]} 0 1
[junit4] 2> 548835 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-2
(-1570303715382919168)]} 0 2
[junit4] 2> 548837 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-2
(-1570303715385016320)]} 0 1
[junit4] 2> 548838 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-4
(1570303715386064896)]} 0 1
[junit4] 2> 548838 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-4
(1570303715386064896)]} 0 2
[junit4] 2> 548838 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-2
(-1570303715385016320)]} 0 3
[junit4] 2> 548840 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-4
(1570303715389210624)]} 0 1
[junit4] 2> 548841 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-4
(1570303715389210624)]} 0 2
[junit4] 2> 548843 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-4
(-1570303715392356352)]} 0 0
[junit4] 2> 548844 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-4
(-1570303715392356352)]} 0 1
[junit4] 2> 548844 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-4
(-1570303715391307776)]} 0 1
[junit4] 2> 548844 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-4
(-1570303715391307776)]} 0 2
[junit4] 2> 548846 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-5
(1570303715395502080)]} 0 1
[junit4] 2> 548847 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-5
(1570303715395502080)]} 0 2
[junit4] 2> 548847 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-5
(1570303715396550656)]} 0 0
[junit4] 2> 548847 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-5
(1570303715396550656)]} 0 1
[junit4] 2> 548850 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-6
(1570303715397599232)]} 0 1
[junit4] 2> 548850 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-6
(1570303715397599232)]} 0 2
[junit4] 2> 548850 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-6
(1570303715398647808)]} 0 0
[junit4] 2> 548850 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-6
(1570303715398647808)]} 0 1
[junit4] 2> 548852 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-7
(1570303715401793536)]} 0 1
[junit4] 2> 548853 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-7
(1570303715401793537)]} 0 1
[junit4] 2> 548853 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-7
(1570303715401793537)]} 0 1
[junit4] 2> 548853 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-7
(1570303715401793536)]} 0 2
[junit4] 2> 548856 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-8
(1570303715404939265)]} 0 0
[junit4] 2> 548856 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-8
(1570303715404939264)]} 0 1
[junit4] 2> 548856 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-8
(1570303715404939265)]} 0 1
[junit4] 2> 548857 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-8
(1570303715404939264)]} 0 3
[junit4] 2> 548859 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-9
(1570303715408084992)]} 0 1
[junit4] 2> 548859 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-9
(1570303715408084992)]} 0 2
[junit4] 2> 548860 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-9
(1570303715409133568)]} 0 1
[junit4] 2> 548861 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-9
(1570303715409133568)]} 0 2
[junit4] 2> 548863 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-7
(-1570303715411230720)]} 0 1
[junit4] 2> 548863 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-7
(-1570303715413327872)]} 0 1
[junit4] 2> 548865 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-7
(-1570303715413327872)]} 0 3
[junit4] 2> 548865 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-7
(-1570303715411230720)]} 0 4
[junit4] 2> 548871 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-10
(1570303715417522177)]} 0 3
[junit4] 2> 548871 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-10
(1570303715417522176)]} 0 4
[junit4] 2> 548872 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-10
(1570303715417522177)]} 0 5
[junit4] 2> 548872 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-10
(1570303715417522176)]} 0 6
[junit4] 2> 548875 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-8
(-1570303715424862208)]} 0 1
[junit4] 2> 548875 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-8
(-1570303715424862209)]} 0 1
[junit4] 2> 548876 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-8
(-1570303715424862208)]} 0 3
[junit4] 2> 548876 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-8
(-1570303715424862209)]} 0 2
[junit4] 2> 548879 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-11
(1570303715429056512)]} 0 0
[junit4] 2> 548879 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-11
(1570303715429056513)]} 0 1
[junit4] 2> 548879 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-11
(1570303715429056513)]} 0 2
[junit4] 2> 548880 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-11
(1570303715429056512)]} 0 3
[junit4] 2> 548882 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-12
(1570303715432202240)]} 0 1
[junit4] 2> 548882 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-12
(1570303715433250816)]} 0 1
[junit4] 2> 548883 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-12
(1570303715433250816)]} 0 1
[junit4] 2> 548883 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-12
(1570303715432202240)]} 0 2
[junit4] 2> 548885 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-10
(-1570303715436396545)]} 0 0
[junit4] 2> 548886 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-10
(-1570303715436396545)]} 0 1
[junit4] 2> 548886 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-10
(-1570303715436396544)]} 0 1
[junit4] 2> 548886 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-10
(-1570303715436396544)]} 0 2
[junit4] 2> 548889 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-13
(1570303715439542272)]} 0 1
[junit4] 2> 548889 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-13
(1570303715439542273)]} 0 1
[junit4] 2> 548889 INFO (qtp1423206858-8296) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-13
(1570303715439542272)]} 0 2
[junit4] 2> 548889 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-13
(1570303715439542273)]} 0 2
[junit4] 2> 548893 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-14
(1570303715443736576)]} 0 1
[junit4] 2> 548893 INFO (qtp1423206858-8300) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-14
(1570303715443736576)]} 0 2
[junit4] 2> 548895 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-14
(1570303715442688000)]} 0 2
[junit4] 2> 548896 INFO (qtp1423206858-8292) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-14
(1570303715442688000)]} 0 6
[junit4] 2> 548897 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-15
(1570303715446882304)]} 0 2
[junit4] 2> 548897 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-15
(1570303715446882304)]} 0 3
[junit4] 2> 548900 INFO (qtp804007706-8294) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-15
(1570303715450028032)]} 0 1
[junit4] 2> 548900 INFO (qtp1423206858-8298) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[1-15
(1570303715450028032)]} 0 2
[junit4] 2> 548901 INFO (qtp804007706-8306) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-11
(-1570303715451076608)]} 0 1
[junit4] 2> 548901 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[2-11
(-1570303715451076608)]} 0 3
[junit4] 2> 548903 INFO (qtp804007706-8307) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[1-11
(-1570303715454222336)]} 0 1
[junit4] 2> 548903 INFO (qtp1423206858-8302) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{delete=[1-11
(-1570303715454222336)]} 0 2
[junit4] 2> 548904 INFO (qtp804007706-8304) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[2-16
(1570303715454222337)]} 0 1
[junit4] 2> 548904 INFO (qtp1423206858-8301) [n:127.0.0.1:53762_solr
c:recoverytest s:shard1 r:core_node2 x:recoverytest_shard1_replica_n2]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n2]
webapp=/solr path=/update params={wt=javabin&version=2}{add=[2-16
(1570303715454222337)]} 0 2
[junit4] 2> 548924 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@7df89456{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 548926 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=707792283
[junit4] 2> 548927 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 548929 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 548930 INFO (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{add=[1-16
(1570303715457368064)]} 0 24
[junit4] 2> 548930 INFO (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.u.p.LogUpdateProcessorFactory [recoverytest_shard1_replica_n1]
webapp=/solr path=/update
params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:53762/solr/recoverytest_shard1_replica_n2/&wt=javabin&version=2}{delete=[2-12
(-1570303715458416640)]} 0 19
[junit4] 2> 548931 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 548934 ERROR (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.h.RequestHandlerBase java.nio.channels.ClosedChannelException
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.onClose(FillInterest.java:135)
[junit4] 2> at
org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:114)
[junit4] 2> at
org.eclipse.jetty.io.ChannelEndPoint.close(ChannelEndPoint.java:120)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:276)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection.close(AbstractConnection.java:220)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.closeNoExceptions(ManagedSelector.java:410)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.access$800(ManagedSelector.java:56)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector$EndPointCloser.run(ManagedSelector.java:749)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 548937 ERROR (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.h.RequestHandlerBase java.nio.channels.ClosedChannelException
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.onClose(FillInterest.java:135)
[junit4] 2> at
org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:114)
[junit4] 2> at
org.eclipse.jetty.io.ChannelEndPoint.close(ChannelEndPoint.java:120)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:276)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection.close(AbstractConnection.java:220)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.closeNoExceptions(ManagedSelector.java:410)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.access$800(ManagedSelector.java:56)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector$EndPointCloser.run(ManagedSelector.java:749)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 548938 ERROR (qtp804007706-8308) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.s.HttpSolrCall null:java.nio.channels.ClosedChannelException
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.onClose(FillInterest.java:135)
[junit4] 2> at
org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:114)
[junit4] 2> at
org.eclipse.jetty.io.ChannelEndPoint.close(ChannelEndPoint.java:120)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:276)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection.close(AbstractConnection.java:220)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.closeNoExceptions(ManagedSelector.java:410)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.access$800(ManagedSelector.java:56)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector$EndPointCloser.run(ManagedSelector.java:749)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 548938 ERROR (qtp804007706-8293) [n:127.0.0.1:53723_solr
c:recoverytest s:shard1 r:core_node1 x:recoverytest_shard1_replica_n1]
o.a.s.s.HttpSolrCall null:java.nio.channels.ClosedChannelException
[junit4] 2> at
org.eclipse.jetty.io.FillInterest.onClose(FillInterest.java:135)
[junit4] 2> at
org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:114)
[junit4] 2> at
org.eclipse.jetty.io.ChannelEndPoint.close(ChannelEndPoint.java:120)
[junit4] 2> at
org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:276)
[junit4] 2> at
org.eclipse.jetty.io.AbstractConnection.close(AbstractConnection.java:220)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.closeNoExceptions(ManagedSelector.java:410)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector.access$800(ManagedSelector.java:56)
[junit4] 2> at
org.eclipse.jetty.io.ManagedSelector$EndPointCloser.run(ManagedSelector.java:749)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 548941 INFO
(TEST-HdfsRecoveryZkTest.test-seed#[D7D9D787996D02BF]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 548943 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_replica_n1] o.a.s.c.SolrCore
[recoverytest_shard1_replica_n1] CLOSING SolrCore
org.apache.solr.core.SolrCore@1af3344e
[junit4] 2> 548951 INFO (IPC Server handler 9 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:48087 is
added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-2c993717-5ef6-4ff2-9074-e1625ae22445:NORMAL:127.0.0.1:50646|RBW],
ReplicaUC[[DISK]DS-3aaceb91-4a16-4938-a5ed-ea62a0dfa977:NORMAL:127.0.0.1:48087|FINALIZED]]}
size 216
[junit4] 2> 548951 INFO (IPC Server handler 9 on 42793) [ ]
BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:50646 is
added to blk_1073741827_1003{UCState=UNDER_CONSTRUCTION, truncateBlock=null,
primaryNodeIndex=-1,
replicas=[ReplicaUC[[DISK]DS-3aaceb91-4a16-4938-a5ed-ea62a0dfa977:NORMAL:127.0.0.1:48087|FINALIZED],
ReplicaUC[[DISK]DS-2db6ce5b-6cce-4113-8131-78eae7e328c1:NORMAL:127.0.0.1:50646|FINALIZED]]}
size 216
[junit4] 2> 548956 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.recoverytest.shard1.replica_n1, tag=452146254
[junit4] 2> 548959 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.recoverytest.shard1.leader, tag=452146254
[junit4] 2> 548962 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_replica_n1] o.a.s.s.h.HdfsDirectory Closing hdfs
directory hdfs://localhost:42793/data/recoverytest/core_node1/data/index
[junit4] 2> 548968 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_replica_n1] o.a.s.s.h.HdfsDirectory Closing hdfs
directory
hdfs://localhost:42793/data/recoverytest/core_node1/data/snapshot_metadata
[junit4] 2> 548968 INFO (coreCloseExecutor-3164-thread-1)
[n:127.0.0.1:53723_solr c:recoverytest s:shard1 r:core_node1
x:recoverytest_shard1_
[...truncated too long message...]
Block pool BP-710501982-10.41.0.5-1497558302412 (Datanode Uuid
e55bf0f5-aee8-4ef5-9fd9-ea892400800c) service to localhost/127.0.0.1:42793
interrupted
[junit4] 2> 566126 WARN (DataNode:
[[[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-002/hdfsBaseDir/data/data1/,
[DISK]file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001/tempDir-002/hdfsBaseDir/data/data2/]]
heartbeating to localhost/127.0.0.1:42793) [ ] o.a.h.h.s.d.DataNode Ending
block pool service for: Block pool BP-710501982-10.41.0.5-1497558302412
(Datanode Uuid e55bf0f5-aee8-4ef5-9fd9-ea892400800c) service to
localhost/127.0.0.1:42793
[junit4] 2> 566138 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ] o.m.log
Stopped HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:0
[junit4] 2> 566244 ERROR
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.h.m.l.MethodMetric Error invoking method getBlocksTotal
[junit4] 2> java.lang.reflect.InvocationTargetException
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.MethodMetric$2.snapshot(MethodMetric.java:111)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.MethodMetric.snapshot(MethodMetric.java:144)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.MetricsRegistry.snapshot(MetricsRegistry.java:401)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.MetricsSourceBuilder$1.getMetrics(MetricsSourceBuilder.java:79)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMetrics(MetricsSourceAdapter.java:194)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.updateJmxCache(MetricsSourceAdapter.java:172)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.getMBeanInfo(MetricsSourceAdapter.java:151)
[junit4] 2> at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getClassName(DefaultMBeanServerInterceptor.java:1804)
[junit4] 2> at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.safeGetClassName(DefaultMBeanServerInterceptor.java:1595)
[junit4] 2> at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813)
[junit4] 2> at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430)
[junit4] 2> at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4] 2> at
com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
[junit4] 2> at
org.apache.hadoop.metrics2.util.MBeans.unregister(MBeans.java:81)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stopMBeans(MetricsSourceAdapter.java:226)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSourceAdapter.stop(MetricsSourceAdapter.java:211)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stopSources(MetricsSystemImpl.java:463)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSystemImpl.stop(MetricsSystemImpl.java:213)
[junit4] 2> at
org.apache.hadoop.metrics2.impl.MetricsSystemImpl.shutdown(MetricsSystemImpl.java:594)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdownInstance(DefaultMetricsSystem.java:72)
[junit4] 2> at
org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.shutdown(DefaultMetricsSystem.java:68)
[junit4] 2> at
org.apache.hadoop.hdfs.server.namenode.metrics.NameNodeMetrics.shutdown(NameNodeMetrics.java:171)
[junit4] 2> at
org.apache.hadoop.hdfs.server.namenode.NameNode.stop(NameNode.java:872)
[junit4] 2> at
org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1726)
[junit4] 2> at
org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniDFSCluster.java:1705)
[junit4] 2> at
org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClass(HdfsTestUtil.java:204)
[junit4] 2> at
org.apache.solr.cloud.hdfs.HdfsRecoveryZkTest.teardownClass(HdfsRecoveryZkTest.java:53)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native
Method)
[junit4] 2> at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
[junit4] 2> at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at
org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:203)
[junit4] 2> at
org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3370)
[junit4] 2> at
org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:5729)
[junit4] 2> ... 54 more
[junit4] 2> 566248 INFO
(SUITE-HdfsRecoveryZkTest-seed#[D7D9D787996D02BF]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:34057 34057
[junit4] 2> NOTE: leaving temporary files on disk at:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsRecoveryZkTest_D7D9D787996D02BF-001
[junit4] 2> Jun 15, 2017 8:25:39 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 35 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=RandomSimilarity(queryNorm=true): {}, locale=ar-BH,
timezone=Europe/Volgograd
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation
1.8.0_131 (64-bit)/cpus=4,threads=2,free=230471280,total=524288000
[junit4] 2> NOTE: All tests run in this JVM: [TestManagedSchema,
TestHdfsUpdateLog, DocValuesNotIndexedTest, TestAuthenticationFramework,
DistributedMLTComponentTest, TestSolrConfigHandlerCloud,
ClassificationUpdateProcessorIntegrationTest, SSLMigrationTest,
TestEmbeddedSolrServerSchemaAPI, UpdateLogTest,
LeaderInitiatedRecoveryOnCommitTest, DocumentBuilderTest, TestXmlQParser,
TestSortByMinMaxFunction, HdfsBasicDistributedZkTest,
HdfsCollectionsAPIDistributedZkTest, TestHashPartitioner, TestExportWriter,
SchemaVersionSpecificBehaviorTest, SolrInfoBeanTest, TestExactStatsCache,
DateRangeFieldTest, TestSolr4Spatial2, TestLegacyTerms, MergeStrategyTest,
ActionThrottleTest, IndexSchemaTest, IndexBasedSpellCheckerTest,
HighlighterMaxOffsetTest, TestFieldResource, TestCloudRecovery,
DistributedFacetPivotSmallTest, DistributedIntervalFacetingTest,
SpatialHeatmapFacetsTest, TestLegacyField, TestDistributedGrouping,
TestSimpleTrackingShardHandler, TestDistributedStatsComponentCardinality,
TestSystemIdResolver, AlternateDirectoryTest, MoreLikeThisHandlerTest,
InfixSuggestersTest, ShardRoutingTest, TestStressRecovery, TestInitQParser,
TestSweetSpotSimilarityFactory, UninvertDocValuesMergePolicyTest,
TestQueryTypes, DistributedTermsComponentTest, TestPivotHelperCode,
SimplePostToolTest, SampleTest, TestCollectionAPIs,
TestDelegationWithHadoopAuth, TestManagedResource, TestFilteredDocIdSet,
DistributedFacetPivotLargeTest, HdfsRecoveryZkTest]
[junit4] Completed [190/725 (1!)] on J1 in 48.15s, 1 test, 1 failure <<<
FAILURES!
[...truncated 45075 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
