You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/10/02 09:49:59 UTC
[JENKINS] Lucene-Solr-7.0-Linux (64bit/jdk-9) - Build # 406 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/406/
Java: 64bit/jdk-9 -XX:+UseCompressedOops -XX:+UseG1GC --illegal-access=deny
1 tests failed.
FAILED: org.apache.solr.cloud.TestTlogReplica.testRecovery
Error Message:
Can not find doc 3 in http://127.0.0.1:45143/solr
Stack Trace:
java.lang.AssertionError: Can not find doc 3 in http://127.0.0.1:45143/solr
at __randomizedtesting.SeedInfo.seed([D83AB919F1451FEB:19CAC0B5DC15D54C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.cloud.TestTlogReplica.checkRTG(TestTlogReplica.java:868)
at org.apache.solr.cloud.TestTlogReplica.testRecovery(TestTlogReplica.java:559)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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 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.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 11466 lines...]
[junit4] Suite: org.apache.solr.cloud.TestTlogReplica
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/init-core-data-001
[junit4] 2> 460834 WARN (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7
[junit4] 2> 460835 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 460835 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 460836 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001
[junit4] 2> 460836 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 460837 INFO (Thread-2492) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 460837 INFO (Thread-2492) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 460842 ERROR (Thread-2492) [ ] 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> 460937 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:43867
[junit4] 2> 460941 INFO (jetty-launcher-667-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 460941 INFO (jetty-launcher-667-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 460942 INFO (jetty-launcher-667-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@776cdbf7{/solr,null,AVAILABLE}
[junit4] 2> 460942 INFO (jetty-launcher-667-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@8e3355f{/solr,null,AVAILABLE}
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@34536c96{HTTP/1.1,[http/1.1]}{127.0.0.1:41103}
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@16e38a34{HTTP/1.1,[http/1.1]}{127.0.0.1:45143}
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-2) [ ] o.e.j.s.Server Started @462994ms
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-1) [ ] o.e.j.s.Server Started @462994ms
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45143}
[junit4] 2> 460944 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41103}
[junit4] 2> 460944 ERROR (jetty-launcher-667-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 460944 ERROR (jetty-launcher-667-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.1
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T09:01:32.240123Z
[junit4] 2> 460945 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T09:01:32.240142Z
[junit4] 2> 460946 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 460946 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 460959 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43867/solr
[junit4] 2> 460959 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43867/solr
[junit4] 2> 460960 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15edc51a6690003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 461004 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 461006 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45143_solr
[junit4] 2> 461007 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.Overseer Overseer (id=98758485091090437-127.0.0.1:45143_solr-n_0000000000) starting
[junit4] 2> 461012 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45143_solr
[junit4] 2> 461015 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 461026 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 461027 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 461028 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41103_solr
[junit4] 2> 461029 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 461029 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 461050 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461056 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461057 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461058 INFO (jetty-launcher-667-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/.
[junit4] 2> 461061 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461070 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461070 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 461071 INFO (jetty-launcher-667-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/.
[junit4] 2> 461098 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 461098 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43867/solr ready
[junit4] 2> 461099 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.TestTlogReplica Using legacyCloud?: false
[junit4] 2> 461102 INFO (qtp753656455-5953) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 461102 INFO (qtp753656455-5953) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 461113 INFO (TEST-TestTlogReplica.testCreateDelete-seed#[D83AB919F1451FEB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateDelete { seed=[D83AB919F1451FEB:C32A485507B5E7DB]}
[junit4] 2> 461127 INFO (OverseerThreadFactory-1878-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection tlog_replica_test_create_delete
[junit4] 2> 461127 WARN (OverseerThreadFactory-1878-thread-1) [ ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 4 on collection tlog_replica_test_create_delete is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 461230 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard1_replica_t1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41103/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461231 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard1_replica_t2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45143/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461231 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard1_replica_t3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41103/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461232 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard1_replica_t4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45143/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461233 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard2_replica_t1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41103/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461233 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard2_replica_t2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45143/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461234 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard2_replica_t3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41103/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461234 INFO (OverseerStateUpdate-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"tlog_replica_test_create_delete_shard2_replica_t4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45143/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 461437 INFO (qtp844266029-5949) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t3&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461437 INFO (qtp753656455-5950) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t2&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461437 INFO (qtp753656455-5948) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t4&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461437 INFO (qtp844266029-5951) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t1&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461437 INFO (qtp844266029-5949) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 461437 INFO (qtp753656455-5950) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 461437 INFO (qtp753656455-5946) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t2&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461437 INFO (qtp844266029-5959) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t1&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461438 INFO (qtp753656455-5957) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t4&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461439 INFO (qtp844266029-6010) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t3&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 461543 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 461544 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 461544 INFO (zkCallback-679-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 461544 INFO (zkCallback-678-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 462448 INFO (qtp753656455-5948) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462448 INFO (qtp753656455-5957) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462448 INFO (qtp753656455-5950) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462449 INFO (qtp753656455-5946) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462454 INFO (qtp753656455-5948) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t4] Schema name=minimal
[junit4] 2> 462454 INFO (qtp753656455-5957) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t4] Schema name=minimal
[junit4] 2> 462455 INFO (qtp844266029-5949) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462455 INFO (qtp844266029-5951) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462456 INFO (qtp753656455-5957) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462456 INFO (qtp753656455-5948) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462456 INFO (qtp753656455-5957) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard2_replica_t4' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462456 INFO (qtp753656455-5948) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard1_replica_t4' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462457 INFO (qtp753656455-5948) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard1.replica_t4' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462457 INFO (qtp753656455-5957) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard2.replica_t4' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462457 INFO (qtp753656455-5957) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462457 INFO (qtp753656455-5948) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462457 INFO (qtp753656455-5957) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard2_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard2_replica_t4/data/]
[junit4] 2> 462457 INFO (qtp753656455-5948) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard1_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard1_replica_t4/data/]
[junit4] 2> 462459 INFO (qtp844266029-6010) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462459 INFO (qtp753656455-5950) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t2] Schema name=minimal
[junit4] 2> 462471 INFO (qtp753656455-5950) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462471 INFO (qtp753656455-5950) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard2_replica_t2' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462471 INFO (qtp753656455-5946) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t2] Schema name=minimal
[junit4] 2> 462471 INFO (qtp844266029-5959) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 462471 INFO (qtp753656455-5950) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard2.replica_t2' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462472 INFO (qtp753656455-5950) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462472 INFO (qtp753656455-5950) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard2_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard2_replica_t2/data/]
[junit4] 2> 462473 INFO (qtp844266029-5949) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t3] Schema name=minimal
[junit4] 2> 462473 INFO (qtp753656455-5946) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462473 INFO (qtp753656455-5946) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard1_replica_t2' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462474 INFO (qtp753656455-5946) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard1.replica_t2' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462474 INFO (qtp753656455-5946) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462474 INFO (qtp753656455-5946) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard1_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard1_replica_t2/data/]
[junit4] 2> 462475 INFO (qtp844266029-5949) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462475 INFO (qtp844266029-5949) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard1_replica_t3' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462475 INFO (qtp844266029-5949) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard1.replica_t3' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462475 INFO (qtp844266029-5949) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462475 INFO (qtp844266029-5949) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard1_replica_t3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard1_replica_t3/data/]
[junit4] 2> 462478 INFO (qtp844266029-5951) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t1] Schema name=minimal
[junit4] 2> 462479 INFO (qtp844266029-5959) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t1] Schema name=minimal
[junit4] 2> 462480 INFO (qtp844266029-6010) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t3] Schema name=minimal
[junit4] 2> 462480 INFO (qtp844266029-5959) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462480 INFO (qtp844266029-5959) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard1_replica_t1' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462481 INFO (qtp844266029-5959) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462481 INFO (qtp844266029-5959) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462481 INFO (qtp844266029-5959) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard1_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard1_replica_t1/data/]
[junit4] 2> 462481 INFO (qtp844266029-5951) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462481 INFO (qtp844266029-5951) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard2_replica_t1' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462482 INFO (qtp844266029-5951) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard2.replica_t1' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462482 INFO (qtp844266029-5951) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462482 INFO (qtp844266029-5951) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard2_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard2_replica_t1/data/]
[junit4] 2> 462485 INFO (qtp844266029-6010) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 462485 INFO (qtp844266029-6010) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_create_delete_shard2_replica_t3' using configuration from collection tlog_replica_test_create_delete, trusted=true
[junit4] 2> 462485 INFO (qtp844266029-6010) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard2.replica_t3' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 462485 INFO (qtp844266029-6010) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 462485 INFO (qtp844266029-6010) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard2_replica_t3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard2_replica_t3/data/]
[junit4] 2> 462599 INFO (qtp753656455-5948) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462599 INFO (qtp753656455-5948) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462602 INFO (qtp753656455-5948) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462602 INFO (qtp753656455-5948) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462608 INFO (qtp844266029-5951) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462608 INFO (qtp844266029-5951) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462612 INFO (qtp844266029-5951) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462612 INFO (qtp844266029-5951) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462614 INFO (qtp753656455-5948) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6c6db4a9[tlog_replica_test_create_delete_shard1_replica_t4] main]
[junit4] 2> 462615 INFO (qtp753656455-5957) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462615 INFO (qtp753656455-5957) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462615 INFO (qtp844266029-5949) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462615 INFO (qtp844266029-5949) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462616 INFO (qtp753656455-5948) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462617 INFO (qtp753656455-5948) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462618 INFO (qtp753656455-5957) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462618 INFO (qtp753656455-5957) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462618 INFO (qtp844266029-5949) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462618 INFO (qtp844266029-5949) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462619 INFO (qtp753656455-5948) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462621 INFO (qtp844266029-5951) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3df19e36[tlog_replica_test_create_delete_shard2_replica_t1] main]
[junit4] 2> 462622 INFO (qtp844266029-5951) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462622 INFO (qtp844266029-5951) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462622 INFO (searcherExecutor-1883-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t4] Registered new searcher Searcher@6c6db4a9[tlog_replica_test_create_delete_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462623 INFO (qtp753656455-5948) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763324960768
[junit4] 2> 462627 INFO (qtp844266029-5949) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3c8396d[tlog_replica_test_create_delete_shard1_replica_t3] main]
[junit4] 2> 462627 INFO (qtp753656455-5957) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5dda7aee[tlog_replica_test_create_delete_shard2_replica_t4] main]
[junit4] 2> 462628 INFO (qtp844266029-5951) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462628 INFO (qtp753656455-5950) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462628 INFO (qtp753656455-5950) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462629 INFO (qtp844266029-5949) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462629 INFO (qtp844266029-5949) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462645 INFO (qtp753656455-5957) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462646 INFO (qtp753656455-5957) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462646 INFO (qtp753656455-5950) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462646 INFO (qtp753656455-5950) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462647 INFO (qtp844266029-5949) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462648 INFO (qtp753656455-5948) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=4 found=1 timeoutin=9998ms
[junit4] 2> 462648 INFO (searcherExecutor-1889-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard2_replica_t1] Registered new searcher Searcher@3df19e36[tlog_replica_test_create_delete_shard2_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462649 INFO (qtp844266029-5951) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763352223744
[junit4] 2> 462651 INFO (qtp753656455-5957) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462652 INFO (qtp844266029-5951) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=4 found=1 timeoutin=9999ms
[junit4] 2> 462653 INFO (searcherExecutor-1887-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t3] Registered new searcher Searcher@3c8396d[tlog_replica_test_create_delete_shard1_replica_t3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462653 INFO (qtp844266029-5949) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763356418048
[junit4] 2> 462654 INFO (searcherExecutor-1884-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard2_replica_t4] Registered new searcher Searcher@5dda7aee[tlog_replica_test_create_delete_shard2_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462654 INFO (qtp753656455-5957) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763357466624
[junit4] 2> 462654 INFO (qtp753656455-5950) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2dcf2496[tlog_replica_test_create_delete_shard2_replica_t2] main]
[junit4] 2> 462656 INFO (qtp753656455-5950) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462656 INFO (qtp753656455-5950) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462659 INFO (qtp753656455-5950) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462659 INFO (qtp753656455-5950) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763362709504
[junit4] 2> 462661 INFO (searcherExecutor-1885-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard2_replica_t2] Registered new searcher Searcher@2dcf2496[tlog_replica_test_create_delete_shard2_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462662 INFO (qtp753656455-5946) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462662 INFO (qtp753656455-5946) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462663 INFO (qtp753656455-5946) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462663 INFO (qtp844266029-5959) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462663 INFO (qtp753656455-5946) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462663 INFO (qtp844266029-5959) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462664 INFO (qtp844266029-5959) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462664 INFO (qtp844266029-5959) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462666 INFO (qtp844266029-5959) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1bd60386[tlog_replica_test_create_delete_shard1_replica_t1] main]
[junit4] 2> 462666 INFO (qtp844266029-5959) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462666 INFO (qtp844266029-5959) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462667 INFO (qtp844266029-5959) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462671 INFO (qtp844266029-5959) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763375292416
[junit4] 2> 462672 INFO (searcherExecutor-1888-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t1] Registered new searcher Searcher@1bd60386[tlog_replica_test_create_delete_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462672 INFO (qtp753656455-5946) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4d1b5840[tlog_replica_test_create_delete_shard1_replica_t2] main]
[junit4] 2> 462673 INFO (qtp844266029-6010) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 462673 INFO (qtp844266029-6010) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 462674 INFO (qtp844266029-6010) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 462674 INFO (qtp844266029-6010) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 462675 INFO (qtp753656455-5946) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462676 INFO (qtp753656455-5946) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462676 INFO (qtp844266029-6010) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7573ad21[tlog_replica_test_create_delete_shard2_replica_t3] main]
[junit4] 2> 462676 INFO (qtp753656455-5946) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462676 INFO (qtp753656455-5946) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763380535296
[junit4] 2> 462677 INFO (qtp844266029-6010) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 462677 INFO (qtp844266029-6010) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 462678 INFO (qtp844266029-6010) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 462678 INFO (qtp844266029-6010) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135763382632448
[junit4] 2> 462679 INFO (searcherExecutor-1886-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t2] Registered new searcher Searcher@4d1b5840[tlog_replica_test_create_delete_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462681 INFO (searcherExecutor-1890-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard2_replica_t3] Registered new searcher Searcher@7573ad21[tlog_replica_test_create_delete_shard2_replica_t3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 462764 INFO (zkCallback-679-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 462764 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 462764 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 462764 INFO (zkCallback-678-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463149 INFO (qtp753656455-5948) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 463149 INFO (qtp753656455-5948) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 463149 INFO (qtp753656455-5948) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t4/
[junit4] 2> 463149 INFO (qtp753656455-5948) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_create_delete_shard1_replica_t4 url=http://127.0.0.1:45143/solr START replicas=[http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard1_replica_t1/, http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t2/, http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard1_replica_t3/] nUpdates=100
[junit4] 2> 463149 INFO (qtp753656455-5948) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_create_delete_shard1_replica_t4 url=http://127.0.0.1:45143/solr DONE. We have no versions. sync failed.
[junit4] 2> 463150 INFO (qtp753656455-6011) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463150 INFO (qtp844266029-5947) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t3] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463150 INFO (qtp844266029-6012) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463151 INFO (qtp753656455-5948) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 463151 INFO (qtp753656455-5948) [ ] 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> 463151 INFO (qtp753656455-5948) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 463151 INFO (qtp753656455-5948) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t4 stopping background replication from leader
[junit4] 2> 463152 INFO (qtp753656455-5948) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t4/ shard1
[junit4] 2> 463153 INFO (qtp844266029-5951) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 463153 INFO (qtp844266029-5951) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 463153 INFO (qtp844266029-5951) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard2_replica_t1/
[junit4] 2> 463153 INFO (qtp844266029-5951) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_create_delete_shard2_replica_t1 url=http://127.0.0.1:41103/solr START replicas=[http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard2_replica_t2/, http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard2_replica_t3/, http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard2_replica_t4/] nUpdates=100
[junit4] 2> 463156 INFO (qtp844266029-5951) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_create_delete_shard2_replica_t1 url=http://127.0.0.1:41103/solr DONE. We have no versions. sync failed.
[junit4] 2> 463157 INFO (qtp753656455-6015) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard2_replica_t2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463157 INFO (qtp753656455-5953) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard2_replica_t4] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463157 INFO (qtp844266029-6014) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard2_replica_t3] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 463157 INFO (qtp844266029-5951) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 463157 INFO (qtp844266029-5951) [ ] 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> 463157 INFO (qtp844266029-5951) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 463158 INFO (qtp844266029-5951) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard2_replica_t1 stopping background replication from leader
[junit4] 2> 463159 INFO (qtp844266029-5951) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard2_replica_t1/ shard2
[junit4] 2> 463262 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463262 INFO (zkCallback-679-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463262 INFO (zkCallback-678-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463262 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463303 INFO (qtp753656455-5948) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 463304 INFO (qtp753656455-5948) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t4&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=1867
[junit4] 2> 463309 INFO (qtp844266029-5951) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 463310 INFO (qtp844266029-5951) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t1&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=1873
[junit4] 2> 463411 INFO (zkCallback-678-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463411 INFO (zkCallback-679-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463411 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463411 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463658 INFO (qtp844266029-5949) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t3 starting background replication from leader
[junit4] 2> 463658 INFO (qtp844266029-5949) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463659 INFO (qtp844266029-5949) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463659 INFO (qtp844266029-5949) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t3&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2222
[junit4] 2> 463664 INFO (qtp753656455-5957) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard2_replica_t4 starting background replication from leader
[junit4] 2> 463664 INFO (qtp753656455-5950) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard2_replica_t2 starting background replication from leader
[junit4] 2> 463664 INFO (qtp753656455-5957) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463664 INFO (qtp753656455-5950) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463664 INFO (qtp753656455-5957) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463664 INFO (qtp753656455-5950) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463665 INFO (qtp753656455-5950) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t2&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2228
[junit4] 2> 463665 INFO (qtp753656455-5957) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t4&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2227
[junit4] 2> 463680 INFO (qtp753656455-5946) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t2 starting background replication from leader
[junit4] 2> 463680 INFO (qtp753656455-5946) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463681 INFO (qtp844266029-6010) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard2_replica_t3 starting background replication from leader
[junit4] 2> 463681 INFO (qtp844266029-6010) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463681 INFO (qtp753656455-5946) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463681 INFO (qtp844266029-6010) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463682 INFO (qtp844266029-6010) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard2_replica_t3&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2242
[junit4] 2> 463682 INFO (qtp753656455-5946) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t2&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2244
[junit4] 2> 463682 INFO (qtp844266029-5959) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t1 starting background replication from leader
[junit4] 2> 463682 INFO (qtp844266029-5959) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 463683 INFO (qtp844266029-5959) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 463684 INFO (qtp844266029-5959) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=tlog_replica_test_create_delete_shard1_replica_t1&action=CREATE&numShards=2&collection=tlog_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2246
[junit4] 2> 463685 INFO (qtp844266029-5956) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 463785 INFO (zkCallback-678-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463785 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463785 INFO (zkCallback-679-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 463785 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_create_delete/state.json] for collection [tlog_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 464051 INFO (indexFetcher-1924-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t4/
[junit4] 2> 464052 INFO (qtp753656455-6015) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t4] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 464052 INFO (indexFetcher-1924-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 464052 INFO (indexFetcher-1924-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 464052 INFO (indexFetcher-1924-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 464052 INFO (indexFetcher-1924-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 464097 INFO (indexFetcher-1934-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t4/
[junit4] 2> 464098 INFO (qtp753656455-5944) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t4] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 464098 INFO (indexFetcher-1934-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 464098 INFO (indexFetcher-1934-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 464098 INFO (indexFetcher-1934-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 464098 INFO (indexFetcher-1934-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 464594 INFO (indexFetcher-1928-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:41103/solr/tlog_replica_test_create_delete_shard2_replica_t1/
[junit4] 2> 464594 INFO (qtp844266029-5947) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard2_replica_t1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 464595 INFO (indexFetcher-1928-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 464595 INFO (indexFetcher-1928-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 464595 INFO (indexFetcher-1928-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 464595 INFO (indexFetcher-1928-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 464686 INFO (qtp844266029-5956) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/c params={} status=0 QTime=3570
[junit4] 2> 464689 INFO (qtp753656455-5955) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :reload with params name=tlog_replica_test_create_delete&action=RELOAD&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 464690 INFO (OverseerThreadFactory-1878-thread-2) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=RELOAD
[junit4] 2> 464690 INFO (OverseerCollectionConfigSetProcessor-98758485091090437-127.0.0.1:45143_solr-n_0000000000) [ ] 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> 464699 INFO (qtp753656455-5950) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464700 INFO (qtp753656455-6011) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464701 INFO (qtp844266029-6041) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464705 INFO (qtp844266029-5945) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464706 INFO (qtp753656455-6011) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t2] Schema name=minimal
[junit4] 2> 464707 INFO (qtp844266029-6014) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464707 INFO (qtp753656455-6011) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464708 INFO (qtp753656455-6011) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard1_replica_t2' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464712 INFO (qtp844266029-6012) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464717 INFO (qtp844266029-6014) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t1] Schema name=minimal
[junit4] 2> 464717 INFO (qtp753656455-6040) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464719 INFO (qtp753656455-5950) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t4] Schema name=minimal
[junit4] 2> 464720 INFO (qtp844266029-5945) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t3] Schema name=minimal
[junit4] 2> 464721 INFO (qtp844266029-6041) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t3] Schema name=minimal
[junit4] 2> 464721 INFO (qtp844266029-6014) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464721 INFO (qtp844266029-6014) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard2_replica_t1' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464723 INFO (qtp753656455-5953) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 464726 INFO (qtp844266029-5945) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464726 INFO (qtp844266029-5945) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard2_replica_t3' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464728 INFO (qtp753656455-6040) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard2_replica_t2] Schema name=minimal
[junit4] 2> 464729 INFO (qtp844266029-6012) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t1] Schema name=minimal
[junit4] 2> 464729 INFO (qtp753656455-5950) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464729 INFO (qtp753656455-5950) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard2_replica_t4' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464733 INFO (qtp844266029-6041) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464733 INFO (qtp844266029-6041) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard1_replica_t3' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464736 INFO (qtp844266029-6012) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464736 INFO (qtp844266029-6012) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard1_replica_t1' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464765 INFO (qtp753656455-6040) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464765 INFO (qtp753656455-6040) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard2_replica_t2' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464766 INFO (qtp753656455-5953) [ ] o.a.s.s.IndexSchema [tlog_replica_test_create_delete_shard1_replica_t4] Schema name=minimal
[junit4] 2> 464768 INFO (qtp753656455-5953) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 464768 INFO (qtp753656455-5953) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'tlog_replica_test_create_delete_shard1_replica_t4' using configuration from collection tlog_replica_test_create_delete
[junit4] 2> 464798 INFO (qtp753656455-6011) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard1.replica_t2' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464798 INFO (qtp753656455-6011) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard1_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard1_replica_t2/data/]
[junit4] 2> 464879 INFO (qtp753656455-6011) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 464879 INFO (qtp753656455-6011) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 464886 INFO (qtp753656455-6011) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@30f0bfb3[tlog_replica_test_create_delete_shard1_replica_t2] main]
[junit4] 2> 464887 INFO (qtp753656455-6011) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 464887 INFO (qtp753656455-6011) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 464887 INFO (qtp753656455-6011) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 464897 INFO (searcherExecutor-1935-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t2] Registered new searcher Searcher@30f0bfb3[tlog_replica_test_create_delete_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 464897 INFO (qtp753656455-6011) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135765709422592
[junit4] 2> 464900 INFO (qtp753656455-6011) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 464900 INFO (qtp753656455-6011) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5543c358[tlog_replica_test_create_delete_shard1_replica_t2] main]
[junit4] 2> 464900 INFO (qtp753656455-6011) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t2] CLOSING SolrCore org.apache.solr.core.SolrCore@4a04852c
[junit4] 2> 464900 INFO (qtp753656455-6011) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.tlog_replica_test_create_delete.shard1.replica_t2, tag=1241810220
[junit4] 2> 464900 INFO (qtp753656455-6011) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3ffaa480: rootName = solr_45143, domain = solr.core.tlog_replica_test_create_delete.shard1.replica_t2, service url = null, agent id = null] for registry solr.core.tlog_replica_test_create_delete.shard1.replica_t2 / com.codahale.metrics.MetricRegistry@79f11b22
[junit4] 2> 464906 INFO (searcherExecutor-1935-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t2] Registered new searcher Searcher@5543c358[tlog_replica_test_create_delete_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 464906 INFO (qtp844266029-6014) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard2.replica_t1' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464906 INFO (qtp844266029-6014) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard2_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard2_replica_t1/data/]
[junit4] 2> 464940 INFO (qtp753656455-5950) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard2.replica_t4' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464941 INFO (qtp844266029-6041) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard1.replica_t3' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464941 INFO (qtp844266029-6041) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard1_replica_t3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard1_replica_t3/data/]
[junit4] 2> 464943 INFO (qtp844266029-5945) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard2.replica_t3' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464943 INFO (qtp844266029-5945) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard2_replica_t3], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard2_replica_t3/data/]
[junit4] 2> 464944 INFO (qtp844266029-6012) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41103.solr.core.tlog_replica_test_create_delete.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464944 INFO (qtp753656455-6040) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard2.replica_t2' (registry 'solr.core.tlog_replica_test_create_delete.shard2.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464944 INFO (qtp844266029-6012) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/tlog_replica_test_create_delete_shard1_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node2/./tlog_replica_test_create_delete_shard1_replica_t1/data/]
[junit4] 2> 464945 INFO (qtp753656455-6011) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.tlog_replica_test_create_delete.shard1.leader, tag=1241810220
[junit4] 2> 464945 INFO (qtp753656455-5950) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard2_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard2_replica_t4/data/]
[junit4] 2> 464945 INFO (qtp753656455-6040) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard2_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard2_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard2_replica_t2/data/]
[junit4] 2> 464945 INFO (qtp753656455-6011) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t2 stopping background replication from leader
[junit4] 2> 464946 INFO (qtp753656455-6011) [ ] o.a.s.c.ZkController tlog_replica_test_create_delete_shard1_replica_t2 starting background replication from leader
[junit4] 2> 464946 INFO (qtp753656455-6011) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 464947 INFO (qtp753656455-6011) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 464947 INFO (qtp753656455-6011) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=tlog_replica_test_create_delete_shard1_replica_t2&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=256
[junit4] 2> 464947 INFO (indexFetcher-1947-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to http://127.0.0.1:45143/solr/tlog_replica_test_create_delete_shard1_replica_t4/
[junit4] 2> 464948 INFO (qtp753656455-5957) [ ] o.a.s.c.S.Request [tlog_replica_test_create_delete_shard1_replica_t4] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 464948 INFO (indexFetcher-1947-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 464948 INFO (indexFetcher-1947-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 464948 INFO (indexFetcher-1947-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 464948 INFO (indexFetcher-1947-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 464953 INFO (qtp753656455-5953) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45143.solr.core.tlog_replica_test_create_delete.shard1.replica_t4' (registry 'solr.core.tlog_replica_test_create_delete.shard1.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@42289f22
[junit4] 2> 464953 INFO (qtp753656455-5953) [ ] o.a.s.c.SolrCore [[tlog_replica_test_create_delete_shard1_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/tlog_replica_test_create_delete_shard1_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001/tempDir-001/node1/./tlog_replica_test_create_delete_shard1_replica_t4/data/]
[junit4] 2> 465002 INFO (qtp844266029-6041) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 465002 INFO (qtp844266029-6041) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 465006 INFO (qtp844266029-6014) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 465006 INFO (qtp844266029-6014) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 465008 INFO (qtp844266029-5945) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 465008 INFO (qtp844266029-5945) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 465011 INFO (qtp844266029-6041) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dc8afc5[tlog_replica_test_create_delete_shard1_replica_t3] main]
[junit4] 2> 465011 INFO (qtp844266029-6014) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@8a5f772[tlog_replica_test_create_delete_shard2_replica_t1] main]
[junit4] 2> 465011 INFO (qtp844266029-5945) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@29f7620d[tlog_replica_test_create_delete_shard2_replica_t3] main]
[junit4] 2> 465011 INFO (qtp753656455-5953) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 465011 INFO (qtp753656455-5953) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 465011 INFO (qtp844266029-6014) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 465012 INFO (qtp844266029-6014) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 465012 INFO (qtp844266029-6014) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 465012 INFO (qtp844266029-6014) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580135765830008832
[junit4] 2> 465017 INFO (qtp753656455-5953) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@408c5f20[tlog_replica_test_create_delete_shard1_replica_t4] main]
[junit4] 2> 465017 INFO (qtp844266029-6012) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 465017 INFO (qtp844266029-6012) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 465018 INFO (qtp753656455-5953) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 465018 INFO (qtp844266029-6041) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 465018 INFO (qtp844266029-6041) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 465019 INFO (qtp844266029-6041) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 465021 INFO (searcherExecutor-1939-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_create_delete_shard1_replica_t3] Registered new searcher Searcher@1dc8afc5[tlog_replica_test_create_delete_shard1_replica_t3] main{ExitableDirectoryReader(Uni
[...truncated too long message...]
ZooKeeper
[junit4] 2> 562484 INFO (jetty-closer-668-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@faf5809{HTTP/1.1,[http/1.1]}{127.0.0.1:45143}
[junit4] 2> 562485 INFO (jetty-closer-668-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1951064356
[junit4] 2> 562485 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 562485 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@21c0d1b8: rootName = solr_45143, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@578c9af3
[junit4] 2> 562484 INFO (jetty-closer-668-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7070889c{HTTP/1.1,[http/1.1]}{127.0.0.1:41103}
[junit4] 2> 562492 INFO (jetty-closer-668-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1822306380
[junit4] 2> 562492 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 562492 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@20e1476b: rootName = solr_41103, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6b7e3cda
[junit4] 2> 562498 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 562498 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2c7454ef: rootName = solr_41103, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1d8e122e
[junit4] 2> 562503 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 562503 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@36aadd08: rootName = solr_41103, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@19b18547
[junit4] 2> 562503 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 562503 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@21209a83: rootName = solr_45143, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@1d8e122e
[junit4] 2> 562509 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 562509 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2b876643: rootName = solr_45143, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@19b18547
[junit4] 2> 562510 INFO (jetty-closer-668-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 562512 INFO (zkCallback-721-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 562514 INFO (jetty-closer-668-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 562515 INFO (jetty-closer-668-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98758485091090455-127.0.0.1:41103_solr-n_0000000006) closing
[junit4] 2> 562515 INFO (OverseerStateUpdate-98758485091090455-127.0.0.1:41103_solr-n_0000000006) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:41103_solr
[junit4] 2> 562523 WARN (zkCallback-721-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 562524 INFO (jetty-closer-668-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@c674682{/solr,null,UNAVAILABLE}
[junit4] 2> 564012 WARN (zkCallback-729-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 564013 INFO (jetty-closer-668-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b23c915{/solr,null,UNAVAILABLE}
[junit4] 2> 564014 ERROR (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] 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> 564015 INFO (SUITE-TestTlogReplica-seed#[D83AB919F1451FEB]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43867 43867
[junit4] 2> 564047 INFO (Thread-2492) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43867 43867
[junit4] 2> 564048 WARN (Thread-2492) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 32 /solr/configs/conf
[junit4] 2> 9 /solr/aliases.json
[junit4] 2> 8 /solr/security.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 28 /solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/state.json
[junit4] 2> 28 /solr/collections/tlog_replica_test_kill_leader/state.json
[junit4] 2> 28 /solr/collections/tlog_replica_test_create_delete/state.json
[junit4] 2> 27 /solr/collections/tlog_replica_test_add_remove_tlog_replica/state.json
[junit4] 2> 24 /solr/collections/tlog_replica_test_recovery/state.json
[junit4] 2> 24 /solr/collections/tlog_replica_test_remove_leader/state.json
[junit4] 2> 24 /solr/collections/tlog_replica_test_basic_leader_election/state.json
[junit4] 2> 23 /solr/collections/tlog_replica_test_kill_tlog_replica/state.json
[junit4] 2> 15 /solr/collections/tlog_replica_test_add_docs/state.json
[junit4] 2> 15 /solr/collections/tlog_replica_test_only_leader_indexes/state.json
[junit4] 2> 15 /solr/collections/tlog_replica_test_delete_by_id/state.json
[junit4] 2> 9 /solr/clusterprops.json
[junit4] 2> 9 /solr/clusterstate.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_real_time_get/state.json
[junit4] 2> 4 /solr/overseer_elect/election/98758485091090438-127.0.0.1:41103_solr-n_0000000001
[junit4] 2> 3 /solr/collections/tlog_replica_test_create_delete/leader_elect/shard1/election/98758485091090437-core_node4-n_0000000000
[junit4] 2> 3 /solr/collections/tlog_replica_test_recovery/leader_elect/shard1/election/98758485091090438-core_node1-n_0000000000
[junit4] 2> 2 /solr/collections/tlog_replica_test_kill_tlog_replica/leader_elect/shard1/election/98758485091090438-core_node2-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/collections
[junit4] 2> 4 /solr/overseer/queue
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_D83AB919F1451FEB-001
[junit4] 2> Oct 02, 2017 9:03:15 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70), sim=RandomSimilarity(queryNorm=true): {}, locale=nn, timezone=America/Kentucky/Louisville
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 9 (64-bit)/cpus=8,threads=1,free=168652296,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrCLIRunExample, TestSmileRequest, TestClassNameShortening, HdfsWriteToMultipleCollectionsTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestDocBasedVersionConstraints, TestSubQueryTransformerCrossCore, TestLegacyNumericUtils, TlogReplayBufferedWhileIndexingTest, DocValuesNotIndexedTest, TestClusterProperties, TestSolrCloudWithHadoopAuthPlugin, TestTrieFacet, MinimalSchemaTest, RequiredFieldsTest, ShowFileRequestHandlerTest, LeaderInitiatedRecoveryOnCommitTest, TolerantUpdateProcessorTest, TestReload, TestJsonFacetRefinement, TestReversedWildcardFilterFactory, FastVectorHighlighterTest, TestLeaderElectionZkExpiry, BlockJoinFacetDistribTest, TestShardHandlerFactory, CustomCollectionTest, TestFieldSortValues, TestSchemalessBufferedUpdates, TestSolrDeletionPolicy2, PingRequestHandlerTest, TestDeleteCollectionOnDownNodes, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestApiFramework, TestBinaryResponseWriter, TestDFISimilarityFactory, TestCloudPivotFacet, HdfsDirectoryFactoryTest, SearchHandlerTest, SaslZkACLProviderTest, TestSurroundQueryParser, TestSolrCoreProperties, SolrCoreCheckLockOnStartupTest, TestZkChroot, TestSlowCompositeReaderWrapper, CollectionsAPIAsyncDistributedZkTest, TestManagedSynonymFilterFactory, SolrTestCaseJ4Test, CheckHdfsIndexTest, TestConfigSets, MissingSegmentRecoveryTest, TestStressReorder, HardAutoCommitTest, TestFieldCacheReopen, TestTlogReplica]
[junit4] Completed [167/730 (1!)] on J2 in 103.99s, 13 tests, 1 failure <<< FAILURES!
[...truncated 38672 lines...]
[JENKINS] Lucene-Solr-7.0-Linux (64bit/jdk-9) - Build # 407 - Still
Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/407/
Java: 64bit/jdk-9 -XX:+UseCompressedOops -XX:+UseParallelGC --illegal-access=deny
3 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1: ClusterState says we are the leader (http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1), but locally we don't think so. Request came from null
Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from server at http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1: ClusterState says we are the leader (http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1), but locally we don't think so. Request came from null
at __randomizedtesting.SeedInfo.seed([9F0192C8D00EA5C2:D774E67CD63D8A57]:0)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:458)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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 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.base/java.lang.Thread.run(Thread.java:844)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1: ClusterState says we are the leader (http://127.0.0.1:39375/solr/awhollynewcollection_0_shard2_replica_n1), but locally we don't think so. Request came from null
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:627)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:516)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
... 1 more
FAILED: org.apache.solr.cloud.TestTlogReplica.testOnlyLeaderIndexes
Error Message:
IndexWriter at leader must see updates
Stack Trace:
java.lang.AssertionError: IndexWriter at leader must see updates
at __randomizedtesting.SeedInfo.seed([9F0192C8D00EA5C2:8300EF45A5ABDB51]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.TestTlogReplica.testOnlyLeaderIndexes(TestTlogReplica.java:469)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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 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.base/java.lang.Thread.run(Thread.java:844)
FAILED: org.apache.solr.cloud.TestTlogReplica.testRecovery
Error Message:
Replica core_node1 not up to date after 0 seconds expected:<4> but was:<2>
Stack Trace:
java.lang.AssertionError: Replica core_node1 not up to date after 0 seconds expected:<4> but was:<2>
at __randomizedtesting.SeedInfo.seed([9F0192C8D00EA5C2:5EF1EB64FD5E6F65]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.TestTlogReplica.waitForNumDocsInAllReplicas(TestTlogReplica.java:743)
at org.apache.solr.cloud.TestTlogReplica.waitForNumDocsInAllReplicas(TestTlogReplica.java:731)
at org.apache.solr.cloud.TestTlogReplica.testRecovery(TestTlogReplica.java:538)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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 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.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 11921 lines...]
[junit4] Suite: org.apache.solr.cloud.TestTlogReplica
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/init-core-data-001
[junit4] 2> 904895 WARN (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8
[junit4] 2> 904895 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 904896 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 904897 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001
[junit4] 2> 904897 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 904897 INFO (Thread-2675) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 904897 INFO (Thread-2675) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 904898 ERROR (Thread-2675) [ ] 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> 904997 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:45449
[junit4] 2> 905004 INFO (jetty-launcher-1103-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 905004 INFO (jetty-launcher-1103-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 905005 INFO (jetty-launcher-1103-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6f61495b{/solr,null,AVAILABLE}
[junit4] 2> 905005 INFO (jetty-launcher-1103-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@34d921b7{/solr,null,AVAILABLE}
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1252614e{SSL,[ssl, http/1.1]}{127.0.0.1:42939}
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.e.j.s.Server Started @906782ms
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5d411732{SSL,[ssl, http/1.1]}{127.0.0.1:34783}
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42939}
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.e.j.s.Server Started @906782ms
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34783}
[junit4] 2> 905007 ERROR (jetty-launcher-1103-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 905007 ERROR (jetty-launcher-1103-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.1
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.1
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T13:17:31.918481Z
[junit4] 2> 905007 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T13:17:31.918490Z
[junit4] 2> 905011 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 905011 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 905020 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45449/solr
[junit4] 2> 905020 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45449/solr
[junit4] 2> 905042 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 905042 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 905043 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34783_solr
[junit4] 2> 905043 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42939_solr
[junit4] 2> 905043 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.Overseer Overseer (id=98759491702489093-127.0.0.1:34783_solr-n_0000000000) starting
[junit4] 2> 905043 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 905043 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 905044 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34783_solr
[junit4] 2> 905045 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 905045 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 905071 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905073 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34783.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905078 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905078 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905078 INFO (jetty-launcher-1103-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/.
[junit4] 2> 905079 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34783.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905080 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34783.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 905080 INFO (jetty-launcher-1103-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node2/.
[junit4] 2> 905103 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 905103 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45449/solr ready
[junit4] 2> 905104 INFO (SUITE-TestTlogReplica-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.TestTlogReplica Using legacyCloud?: false
[junit4] 2> 905114 INFO (qtp567539492-7811) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 905115 INFO (qtp567539492-7811) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 905120 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testKillLeader
[junit4] 2> 905121 INFO (qtp567539492-7820) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&replicationFactor=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_kill_leader&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 905122 INFO (OverseerThreadFactory-2248-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection tlog_replica_test_kill_leader
[junit4] 2> 905225 INFO (OverseerStateUpdate-98759491702489093-127.0.0.1:34783_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_kill_leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_kill_leader_shard1_replica_t1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:42939/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 905226 INFO (OverseerStateUpdate-98759491702489093-127.0.0.1:34783_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_kill_leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_kill_leader_shard1_replica_t2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:34783/solr",
[junit4] 2> "type":"TLOG"}
[junit4] 2> 905431 INFO (qtp567539492-7813) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=tlog_replica_test_kill_leader_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_kill_leader&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 905432 INFO (qtp567539492-7813) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 905450 INFO (qtp148816175-7812) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_kill_leader_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_kill_leader&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 905451 INFO (qtp148816175-7812) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 905556 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 905556 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 905556 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 905556 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 906442 INFO (qtp567539492-7813) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 906448 INFO (qtp567539492-7813) [ ] o.a.s.s.IndexSchema [tlog_replica_test_kill_leader_shard1_replica_t1] Schema name=minimal
[junit4] 2> 906450 INFO (qtp567539492-7813) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 906450 INFO (qtp567539492-7813) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_kill_leader_shard1_replica_t1' using configuration from collection tlog_replica_test_kill_leader, trusted=true
[junit4] 2> 906450 INFO (qtp567539492-7813) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.core.tlog_replica_test_kill_leader.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_kill_leader.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 906450 INFO (qtp567539492-7813) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 906451 INFO (qtp567539492-7813) [ ] o.a.s.c.SolrCore [[tlog_replica_test_kill_leader_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/tlog_replica_test_kill_leader_shard1_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/./tlog_replica_test_kill_leader_shard1_replica_t1/data/]
[junit4] 2> 906461 INFO (qtp148816175-7812) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 906476 INFO (qtp148816175-7812) [ ] o.a.s.s.IndexSchema [tlog_replica_test_kill_leader_shard1_replica_t2] Schema name=minimal
[junit4] 2> 906478 INFO (qtp148816175-7812) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 906478 INFO (qtp148816175-7812) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_kill_leader_shard1_replica_t2' using configuration from collection tlog_replica_test_kill_leader, trusted=true
[junit4] 2> 906478 INFO (qtp148816175-7812) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34783.solr.core.tlog_replica_test_kill_leader.shard1.replica_t2' (registry 'solr.core.tlog_replica_test_kill_leader.shard1.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 906478 INFO (qtp148816175-7812) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 906479 INFO (qtp148816175-7812) [ ] o.a.s.c.SolrCore [[tlog_replica_test_kill_leader_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node2/tlog_replica_test_kill_leader_shard1_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node2/./tlog_replica_test_kill_leader_shard1_replica_t2/data/]
[junit4] 2> 906501 INFO (qtp567539492-7813) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 906501 INFO (qtp567539492-7813) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 906501 INFO (qtp567539492-7813) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 906502 INFO (qtp567539492-7813) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 906502 INFO (qtp567539492-7813) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@42fd9194[tlog_replica_test_kill_leader_shard1_replica_t1] main]
[junit4] 2> 906503 INFO (qtp567539492-7813) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 906503 INFO (qtp567539492-7813) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 906503 INFO (qtp567539492-7813) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 906504 INFO (searcherExecutor-2253-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t1] Registered new searcher Searcher@42fd9194[tlog_replica_test_kill_leader_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 906504 INFO (qtp567539492-7813) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580151868924887040
[junit4] 2> 906506 INFO (qtp567539492-7813) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 906509 INFO (qtp148816175-7812) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 906509 INFO (qtp148816175-7812) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 906510 INFO (qtp148816175-7812) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 906510 INFO (qtp148816175-7812) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 906510 INFO (qtp148816175-7812) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@336ce8f5[tlog_replica_test_kill_leader_shard1_replica_t2] main]
[junit4] 2> 906511 INFO (qtp148816175-7812) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 906511 INFO (qtp148816175-7812) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 906511 INFO (qtp148816175-7812) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 906512 INFO (searcherExecutor-2254-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t2] Registered new searcher Searcher@336ce8f5[tlog_replica_test_kill_leader_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 906512 INFO (qtp148816175-7812) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580151868933275648
[junit4] 2> 906608 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 906608 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 906608 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 906608 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907006 INFO (qtp567539492-7813) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 907007 INFO (qtp567539492-7813) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 907007 INFO (qtp567539492-7813) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/
[junit4] 2> 907007 INFO (qtp567539492-7813) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_kill_leader_shard1_replica_t1 url=https://127.0.0.1:42939/solr START replicas=[https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/] nUpdates=100
[junit4] 2> 907007 INFO (qtp567539492-7813) [ ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_kill_leader_shard1_replica_t1 url=https://127.0.0.1:42939/solr DONE. We have no versions. sync failed.
[junit4] 2> 907010 INFO (qtp148816175-7815) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 907010 INFO (qtp567539492-7813) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 907010 INFO (qtp567539492-7813) [ ] 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> 907010 INFO (qtp567539492-7813) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 907010 INFO (qtp567539492-7813) [ ] o.a.s.c.ZkController tlog_replica_test_kill_leader_shard1_replica_t1 stopping background replication from leader
[junit4] 2> 907011 INFO (qtp567539492-7813) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/ shard1
[junit4] 2> 907113 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907113 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907113 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907113 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907162 INFO (qtp567539492-7813) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 907163 INFO (qtp567539492-7813) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=tlog_replica_test_kill_leader_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_kill_leader&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=1731
[junit4] 2> 907264 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907264 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907264 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907264 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907516 INFO (qtp148816175-7812) [ ] o.a.s.c.ZkController tlog_replica_test_kill_leader_shard1_replica_t2 starting background replication from leader
[junit4] 2> 907516 INFO (qtp148816175-7812) [ ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 907518 INFO (qtp148816175-7812) [ ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 907518 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/
[junit4] 2> 907519 INFO (qtp148816175-7812) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_kill_leader_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_kill_leader&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2069
[junit4] 2> 907521 INFO (qtp567539492-7813) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 907522 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 907522 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 907522 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 907522 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 907523 INFO (qtp567539492-7820) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 907623 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907624 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907624 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 907624 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 908523 INFO (qtp567539492-7820) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&replicationFactor=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_kill_leader&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=2&wt=javabin&version=2} status=0 QTime=3401
[junit4] 2> 908531 INFO (qtp148816175-7825) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/&wt=javabin&version=2}{add=[1 (1580151871046156288)]} 0 0
[junit4] 2> 908532 INFO (qtp567539492-7822) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1580151871046156288)]} 0 4
[junit4] 2> 908533 INFO (qtp148816175-7827) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 908535 INFO (qtp567539492-7816) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1580151871054544896,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 908535 INFO (qtp567539492-7816) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@166c771 commitCommandVersion:1580151871054544896
[junit4] 2> 908538 INFO (qtp567539492-7816) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@11624e1e[tlog_replica_test_kill_leader_shard1_replica_t1] main]
[junit4] 2> 908539 INFO (qtp567539492-7816) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 908540 INFO (searcherExecutor-2253-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t1] Registered new searcher Searcher@11624e1e[tlog_replica_test_kill_leader_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C1)))}
[junit4] 2> 908540 INFO (qtp567539492-7816) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 908540 INFO (qtp567539492-7811) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/update params={_stateVer_=tlog_replica_test_kill_leader:6&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
[junit4] 2> 908543 INFO (qtp567539492-7816) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 908546 INFO (qtp567539492-7811) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 908550 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 908650 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 908751 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 908852 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 908953 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909054 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909123 INFO (OverseerCollectionConfigSetProcessor-98759491702489093-127.0.0.1:34783_solr-n_0000000000) [ ] 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> 909155 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909256 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909357 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909458 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909559 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909660 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909760 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909861 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 909962 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910063 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910164 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910265 INFO (qtp148816175-7825) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910366 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910467 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 910519 INFO (qtp567539492-7814) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 910519 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 910519 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 1506950255446
[junit4] 2> 910519 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 910519 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 910519 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 910520 INFO (qtp567539492-7811) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 910520 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 13
[junit4] 2> 910521 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@5af1945c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6284a187)
[junit4] 2> 910522 INFO (qtp567539492-7824) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910523 INFO (qtp567539492-7816) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910524 INFO (qtp567539492-7814) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910525 INFO (qtp567539492-7811) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910525 INFO (qtp567539492-7824) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910526 INFO (qtp567539492-7816) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910527 INFO (qtp567539492-7814) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910528 INFO (qtp567539492-7811) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910529 INFO (qtp567539492-7824) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene70_0.dvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910529 INFO (qtp567539492-7816) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene70_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910530 INFO (qtp567539492-7814) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910531 INFO (qtp567539492-7811) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910531 INFO (qtp567539492-7824) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 910532 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=2364) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@5af1945c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6284a187)
[junit4] 2> 910533 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 910533 INFO (indexFetcher-2264-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1577c096[tlog_replica_test_kill_leader_shard1_replica_t2] main]
[junit4] 2> 910534 INFO (searcherExecutor-2254-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t2] Registered new searcher Searcher@1577c096[tlog_replica_test_kill_leader_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C1)))}
[junit4] 2> 910568 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 910568 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.ChaosMonkey monkey: kill jetty! 42939
[junit4] 2> 910569 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1252614e{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 910569 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=126493101
[junit4] 2> 910570 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 910570 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@aded87b: rootName = solr_42939, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@15f395ba
[junit4] 2> 910575 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 910575 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@15330cbb: rootName = solr_42939, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@79fdc30c
[junit4] 2> 910580 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 910580 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@51306078: rootName = solr_42939, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@46352c77
[junit4] 2> 910581 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 910582 INFO (coreCloseExecutor-2266-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t1] CLOSING SolrCore org.apache.solr.core.SolrCore@54e50c77
[junit4] 2> 910582 INFO (coreCloseExecutor-2266-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.tlog_replica_test_kill_leader.shard1.replica_t1, tag=1424297079
[junit4] 2> 910582 INFO (coreCloseExecutor-2266-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@124a7a6a: rootName = solr_42939, domain = solr.core.tlog_replica_test_kill_leader.shard1.replica_t1, service url = null, agent id = null] for registry solr.core.tlog_replica_test_kill_leader.shard1.replica_t1 / com.codahale.metrics.MetricRegistry@40832392
[junit4] 2> 910584 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 910584 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 910584 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 910584 INFO (zkCallback-1115-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 910584 INFO (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 910589 INFO (coreCloseExecutor-2266-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.tlog_replica_test_kill_leader.shard1.leader, tag=1424297079
[junit4] 2> 910591 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 910591 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 910592 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 910693 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 910693 INFO (zkCallback-1114-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 910693 INFO (zkCallback-1114-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 912091 WARN (zkCallback-1115-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 912092 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6f61495b{/solr,null,UNAVAILABLE}
[junit4] 2> 912092 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.ChaosMonkey monkey: stop jetty! 42939
[junit4] 2> 913092 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/
[junit4] 2> 913092 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 913092 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/ has no replicas
[junit4] 2> 913093 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.ZkController tlog_replica_test_kill_leader_shard1_replica_t2 stopping background replication from leader
[junit4] 2> 913093 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.ShardLeaderElectionContext New leader does not have old tlog to replay
[junit4] 2> 913094 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/ shard1
[junit4] 2> 913095 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 913095 INFO (zkCallback-1114-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 913095 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [1])
[junit4] 2> 913596 INFO (qtp148816175-7812) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1580151876360339456)]} 0 1
[junit4] 2> 913598 INFO (qtp148816175-7827) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1580151876363485184,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 913598 INFO (qtp148816175-7827) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@72934bdf commitCommandVersion:1580151876363485184
[junit4] 2> 913600 INFO (qtp148816175-7827) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2cbba1b9[tlog_replica_test_kill_leader_shard1_replica_t2] main]
[junit4] 2> 913601 INFO (qtp148816175-7827) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 913601 INFO (searcherExecutor-2254-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t2] Registered new searcher Searcher@2cbba1b9[tlog_replica_test_kill_leader_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.1):C1) Uninverting(_1(7.0.1):C1)))}
[junit4] 2> 913601 INFO (qtp148816175-7827) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/update params={_stateVer_=tlog_replica_test_kill_leader:9&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 3
[junit4] 2> 913604 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=2 status=0 QTime=0
[junit4] 2> 913605 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.ChaosMonkey monkey: starting jetty! 42939
[junit4] 2> 913606 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 913607 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@78faeb38{/solr,null,AVAILABLE}
[junit4] 2> 913607 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@62f1c81f{SSL,[ssl, http/1.1]}{127.0.0.1:42939}
[junit4] 2> 913607 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.e.j.s.Server Started @915382ms
[junit4] 2> 913608 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42939}
[junit4] 2> 913608 ERROR (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 913608 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.1
[junit4] 2> 913608 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 913608 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 913608 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-02T13:17:40.519853Z
[junit4] 2> 913610 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 913617 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45449/solr
[junit4] 2> 913620 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 913621 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 913621 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42939_solr
[junit4] 2> 913622 INFO (zkCallback-1126-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 913622 INFO (zkCallback-1114-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 913622 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 913660 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 913666 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 913666 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 913667 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/.
[junit4] 2> 913667 INFO (TEST-TestTlogReplica.testKillLeader-seed#[9F0192C8D00EA5C2]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [tlog_replica_test_kill_leader_shard1_replica_t1]
[junit4] 2> 913667 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 913671 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
[junit4] 2> 913674 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.s.IndexSchema [tlog_replica_test_kill_leader_shard1_replica_t1] Schema name=minimal
[junit4] 2> 913675 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 913675 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_kill_leader_shard1_replica_t1' using configuration from collection tlog_replica_test_kill_leader, trusted=true
[junit4] 2> 913675 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42939.solr.core.tlog_replica_test_kill_leader.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_kill_leader.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2cd4c5fc
[junit4] 2> 913675 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 913675 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.c.SolrCore [[tlog_replica_test_kill_leader_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/tlog_replica_test_kill_leader_shard1_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_9F0192C8D00EA5C2-001/tempDir-001/node1/./tlog_replica_test_kill_leader_shard1_replica_t1/data/]
[junit4] 2> 913697 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 913697 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 913697 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 913697 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 913698 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1bff57aa[tlog_replica_test_kill_leader_shard1_replica_t1] main]
[junit4] 2> 913698 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 913698 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 913699 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 913699 INFO (searcherExecutor-2274-thread-1) [ ] o.a.s.c.SolrCore [tlog_replica_test_kill_leader_shard1_replica_t1] Registered new searcher Searcher@1bff57aa[tlog_replica_test_kill_leader_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 913699 INFO (coreLoadExecutor-2273-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580151876469391360
[junit4] 2> 913701 INFO (coreZkRegister-2268-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:tlog_replica_test_kill_leader_shard1_replica_t1
[junit4] 2> 913701 INFO (updateExecutor-1123-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.ZkController tlog_replica_test_kill_leader_shard1_replica_t1 stopping background replication from leader
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[tlog_replica_test_kill_leader_shard1_replica_t1]
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 913701 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [tlog_replica_test_kill_leader_shard1_replica_t1] as recovering, leader is [https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/] and I am [https://127.0.0.1:42939/solr/tlog_replica_test_kill_leader_shard1_replica_t1/]
[junit4] 2> 913702 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:34783/solr]; [WaitForState: action=PREPRECOVERY&core=tlog_replica_test_kill_leader_shard1_replica_t2&nodeName=127.0.0.1:42939_solr&coreNodeName=core_node1&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 913704 INFO (qtp148816175-7815) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node1, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true, maxTime: 183 s
[junit4] 2> 913704 INFO (qtp148816175-7815) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=tlog_replica_test_kill_leader, shard=shard1, thisCore=tlog_replica_test_kill_leader_shard1_replica_t2, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:42939_solr, coreNodeName=core_node1, onlyIfActiveCheckResult=false, nodeProps: core_node1:{"core":"tlog_replica_test_kill_leader_shard1_replica_t1","base_url":"https://127.0.0.1:42939/solr","node_name":"127.0.0.1:42939_solr","state":"down","type":"TLOG"}
[junit4] 2> 913803 INFO (zkCallback-1121-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 913803 INFO (zkCallback-1114-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 913803 INFO (zkCallback-1114-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 913803 INFO (zkCallback-1126-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 913803 INFO (zkCallback-1126-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_kill_leader/state.json] for collection [tlog_replica_test_kill_leader] has occurred - updating... (live nodes size: [2])
[junit4] 2> 914704 INFO (qtp148816175-7815) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=tlog_replica_test_kill_leader, shard=shard1, thisCore=tlog_replica_test_kill_leader_shard1_replica_t2, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:42939_solr, coreNodeName=core_node1, onlyIfActiveCheckResult=false, nodeProps: core_node1:{"core":"tlog_replica_test_kill_leader_shard1_replica_t1","base_url":"https://127.0.0.1:42939/solr","node_name":"127.0.0.1:42939_solr","state":"recovering","type":"TLOG"}
[junit4] 2> 914704 INFO (qtp148816175-7815) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 914704 INFO (qtp148816175-7815) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:42939_solr&onlyIfLeaderActive=true&core=tlog_replica_test_kill_leader_shard1_replica_t2&coreNodeName=core_node1&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
[junit4] 2> 915208 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting Replication Recovery.
[junit4] 2> 915208 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to replicate from [https://127.0.0.1:34783/solr/tlog_replica_test_kill_leader_shard1_replica_t2/].
[junit4] 2> 915210 INFO (qtp148816175-7827) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1580151878053789696,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 915210 INFO (qtp148816175-7827) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 915210 INFO (qtp148816175-7827) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 915210 INFO (qtp148816175-7827) [ ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/update params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2}{commit=} 0 0
[junit4] 2> 915212 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 915212 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 3
[junit4] 2> 915212 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 1506950260509
[junit4] 2> 915212 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 915212 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 915212 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 915213 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 915213 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 25
[junit4] 2> 915214 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 915214 INFO (recoveryExecutor-1124-thread-1) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@ebd82ba lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4b2435f2)
[junit4] 2> 915219 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=4
[junit4] 2> 915220 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915222 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915226 INFO (qtp148816175-7815) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915227 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915228 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915229 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915230 INFO (qtp148816175-7815) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915230 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene70_0.dvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915231 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0_Lucene70_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915232 INFO (qtp148816175-7812) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915233 INFO (qtp148816175-7815) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915233 INFO (qtp148816175-7827) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 915234 INFO (qtp148816175-7817) [ ] o.a.s.c.S.Request [tlog_replica_test_kill_leader_shard1_replica_t2] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Lucene70_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4]
[...truncated too long message...]
75 INFO (jetty-closer-3397-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4f31d34b: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@5fdcffb9
[junit4] 2> 1013375 INFO (coreCloseExecutor-4136-thread-1) [ ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@35b711e7
[junit4] 2> 1013375 INFO (coreCloseExecutor-4136-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfdeletedcollection.shard2.replica_n1, tag=901190119
[junit4] 2> 1013375 INFO (coreCloseExecutor-4136-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@56642fd9: rootName = null, domain = solr.core.halfdeletedcollection.shard2.replica_n1, service url = null, agent id = null] for registry solr.core.halfdeletedcollection.shard2.replica_n1 / com.codahale.metrics.MetricRegistry@304a14e4
[junit4] 2> 1013376 INFO (jetty-closer-3397-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1013376 INFO (zkCallback-3415-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1013376 INFO (zkCallback-3417-thread-4) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1013377 INFO (zkCallback-3418-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1013379 INFO (zkCallback-3415-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 1013379 INFO (zkCallback-3418-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 1013381 INFO (coreCloseExecutor-4135-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfdeletedcollection.shard1.leader, tag=2007326265
[junit4] 2> 1013382 INFO (coreCloseExecutor-4136-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfdeletedcollection.shard2.leader, tag=901190119
[junit4] 2> 1013382 INFO (jetty-closer-3397-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98759493285642252-127.0.0.1:36997_solr-n_0000000001) closing
[junit4] 2> 1013382 INFO (OverseerStateUpdate-98759493285642252-127.0.0.1:36997_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:36997_solr
[junit4] 2> 1014876 WARN (zkCallback-3440-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1014877 INFO (jetty-closer-3397-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@527922ae{/solr,null,UNAVAILABLE}
[junit4] 2> 1014879 WARN (zkCallback-3417-thread-4) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1014879 INFO (jetty-closer-3397-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@70fcd6fe{/solr,null,UNAVAILABLE}
[junit4] 2> 1014888 WARN (zkCallback-3418-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1014888 WARN (zkCallback-3415-thread-5) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1014888 INFO (jetty-closer-3397-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@309226b{/solr,null,UNAVAILABLE}
[junit4] 2> 1014889 INFO (jetty-closer-3397-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@13c3a049{/solr,null,UNAVAILABLE}
[junit4] 2> 1014889 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[9F0192C8D00EA5C2]-worker) [ ] 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> 1014889 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[9F0192C8D00EA5C2]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:35293 35293
[junit4] 2> 1024895 INFO (Thread-5844) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:35293 35293
[junit4] 2> 1024895 WARN (Thread-5844) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 18 /solr/configs/conf
[junit4] 2> 10 /solr/aliases.json
[junit4] 2> 10 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 44 /solr/collections/addReplicaColl/state.json
[junit4] 2> 32 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 15 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 13 /solr/collections/halfdeletedcollection/state.json
[junit4] 2> 10 /solr/collections/onlyinzk/state.json
[junit4] 2> 10 /solr/clusterstate.json
[junit4] 2> 5 /solr/collections/created_and_deleted/state.json
[junit4] 2> 5 /solr/collections/halfcollectionblocker2/state.json
[junit4] 2> 4 /solr/collections/halfcollectionblocker/state.json
[junit4] 2> 4 /solr/collections/halfcollection/state.json
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/98759493285642257-core_node1-n_0000000000
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/98759493285642257-core_node5-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 380 /solr/collections
[junit4] 2> 10 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_9F0192C8D00EA5C2-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=PostingsFormat(name=Memory), id=FST50}, docValues:{}, maxPointsInLeafNode=158, maxMBSortInHeap=6.214903941378009, sim=RandomSimilarity(queryNorm=true): {}, locale=fr-BL, timezone=MET
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 9 (64-bit)/cpus=8,threads=1,free=227920448,total=524288000
[junit4] 2> NOTE: All tests run in this JVM: [LoggingHandlerTest, TestManagedStopFilterFactory, PrimUtilsTest, ZkSolrClientTest, TestNamedUpdateProcessors, TestRandomFlRTGCloud, TestNumericTokenStream, NodeMutatorTest, TestReloadAndDeleteDocs, DistributedIntervalFacetingTest, SmileWriterTest, TestLeaderElectionWithEmptyReplica, TestUseDocValuesAsStored2, TestFastLRUCache, NoCacheHeaderTest, CdcrRequestHandlerTest, ConnectionReuseTest, TestPayloadCheckQParserPlugin, BlockJoinFacetSimpleTest, CreateCollectionCleanupTest, EnumFieldTest, V2StandaloneTest, TestTolerantUpdateProcessorRandomCloud, CurrencyFieldTypeTest, TestGraphTermsQParserPlugin, TestCloudManagedSchema, RankQueryTest, HttpSolrCallGetCoreTest, TestMultiValuedNumericRangeQuery, TestExpandComponent, SystemInfoHandlerTest, BigEndianAscendingWordSerializerTest, TestNestedDocsSort, TestStressLiveNodes, ExitableDirectoryReaderTest, TestCoreContainer, SparseHLLTest, BJQParserTest, TestPrepRecovery, ResourceLoaderTest, CloudExitableDirectoryReaderTest, TestSubQueryTransformer, DeleteLastCustomShardedReplicaTest, LeaderFailureAfterFreshStartTest, ScriptEngineTest, TestPostingsSolrHighlighter, TestCollapseQParserPlugin, TestConfigSetProperties, TestSolrIndexConfig, ZkControllerTest, TestStressVersions, ChaosMonkeySafeLeaderWithPullReplicasTest, TestCharFilters, TestSolrCoreParser, TestMinMaxOnMultiValuedField, HdfsDirectoryTest, ConvertedLegacyTest, TestRecoveryHdfs, TestSimpleQParserPlugin, BadCopyFieldTest, TestBackupRepositoryFactory, TestCoreDiscovery, TestCloudRecovery, TestBlobHandler, SliceStateTest, PropertiesRequestHandlerTest, TestSolrCloudWithSecureImpersonation, DocValuesMultiTest, TestPerFieldSimilarityWithDefaultOverride, TestSimpleTrackingShardHandler, DistanceFunctionTest, CursorMarkTest, TestFieldResource, TestFieldCacheSortRandom, UpdateRequestProcessorFactoryTest, SpatialFilterTest, TestLegacyFieldCache, TestUninvertingReader, BasicFunctionalityTest, TestManagedSchemaAPI, BlockCacheTest, MoveReplicaHDFSUlogDirTest, DocExpirationUpdateProcessorFactoryTest, DistributedExpandComponentTest, TestClassicSimilarityFactory, HdfsUnloadDistributedZkTest, OverseerCollectionConfigSetProcessorTest, FullHLLTest, TestImpersonationWithHadoopAuth, StatelessScriptUpdateProcessorFactoryTest, TestLegacyFieldReuse, TestSolrJ, TestCryptoKeys, VMParamsZkACLAndCredentialsProvidersTest, FileBasedSpellCheckerTest, TestSearchPerf, TestHdfsUpdateLog, DistributedFacetPivotLongTailTest, TestAtomicUpdateErrorCases, SuggestComponentContextFilterQueryTest, IndexSchemaRuntimeFieldTest, TestCustomSort, IndexSchemaTest, SpellCheckCollatorWithCollapseTest, TestTrackingShardHandlerFactory, SubstringBytesRefFilterTest, SolrMetricReporterTest, SpellCheckComponentTest, TestAuthenticationFramework, ReplicaListTransformerTest, DisMaxRequestHandlerTest, TestDownShardTolerantSearch, SOLR749Test, TestJavabinTupleStreamParser, DirectSolrConnectionTest, AssignTest, SolrCLIZkUtilsTest, TestDistributedGrouping, PreAnalyzedUpdateProcessorTest, CoreMergeIndexesAdminHandlerTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [297/730 (2!)] on J1 in 95.67s, 19 tests, 1 error <<< FAILURES!
[...truncated 38122 lines...]