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...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
