You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/11/19 19:46:49 UTC
[JENKINS] Lucene-Solr-Tests-7.x - Build # 247 - Still Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/247/
4 tests failed.
FAILED: org.apache.solr.cloud.TestPullReplica.testKillLeader
Error Message:
Replica core_node4 not up to date after 10 seconds expected:<1> but was:<0>
Stack Trace:
java.lang.AssertionError: Replica core_node4 not up to date after 10 seconds expected:<1> but was:<0>
at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454:B9FE877324E1B002]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.TestPullReplica.waitForNumDocsInAllReplicas(TestPullReplica.java:508)
at org.apache.solr.cloud.TestPullReplica.doTestNoLeader(TestPullReplica.java:456)
at org.apache.solr.cloud.TestPullReplica.testKillLeader(TestPullReplica.java:289)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
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:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.core.TestLazyCores.testNoCommit
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454:2F88D2168D7D47F1]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:901)
at org.apache.solr.core.TestLazyCores.check10(TestLazyCores.java:847)
at org.apache.solr.core.TestLazyCores.testNoCommit(TestLazyCores.java:829)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
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:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound='10']
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int><lst name="params"><str name="q">*:*</str></lst></lst><result name="response" numFound="0" start="0"></result>
</response>
request was:q=*:*
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:894)
... 41 more
FAILED: junit.framework.TestSuite.org.apache.solr.core.TestLazyCores
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores: 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores:
1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.core.TestLazyCores
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454]:0)
Build Log:
[...truncated 11720 lines...]
[junit4] Suite: org.apache.solr.cloud.TestPullReplica
[junit4] 2> 290433 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/init-core-data-001
[junit4] 2> 290433 WARN (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 290539 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 290541 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 290687 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001
[junit4] 2> 290687 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 290701 INFO (Thread-86) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 290702 INFO (Thread-86) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 290745 ERROR (Thread-86) [ ] 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> 290811 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44818
[junit4] 2> 290951 INFO (jetty-launcher-104-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 290951 INFO (jetty-launcher-104-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 290972 INFO (jetty-launcher-104-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@30bf189a{/solr,null,AVAILABLE}
[junit4] 2> 291056 INFO (jetty-launcher-104-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6928c715{/solr,null,AVAILABLE}
[junit4] 2> 291081 INFO (jetty-launcher-104-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@68078061{SSL,[ssl, http/1.1]}{127.0.0.1:45743}
[junit4] 2> 291083 INFO (jetty-launcher-104-thread-1) [ ] o.e.j.s.Server Started @306995ms
[junit4] 2> 291082 INFO (jetty-launcher-104-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6018542f{SSL,[ssl, http/1.1]}{127.0.0.1:35285}
[junit4] 2> 291083 INFO (jetty-launcher-104-thread-2) [ ] o.e.j.s.Server Started @306995ms
[junit4] 2> 291083 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45743}
[junit4] 2> 291083 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35285}
[junit4] 2> 291096 ERROR (jetty-launcher-104-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 291096 ERROR (jetty-launcher-104-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 291169 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 291169 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-19T17:39:41.721Z
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 291190 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-19T17:39:41.721Z
[junit4] 2> 291338 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 291353 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 291508 INFO (jetty-launcher-104-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44818/solr
[junit4] 2> 291600 INFO (jetty-launcher-104-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44818/solr
[junit4] 2> 293580 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 293614 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35285_solr
[junit4] 2> 293615 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.c.Overseer Overseer (id=99032313445285892-127.0.0.1:35285_solr-n_0000000000) starting
[junit4] 2> 293715 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35285_solr
[junit4] 2> 293740 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 293742 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 293813 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 293814 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45743_solr
[junit4] 2> 293845 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 293920 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 295034 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295055 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295217 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295218 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295313 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295313 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 295219 INFO (jetty-launcher-104-thread-2) [n:127.0.0.1:35285_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/.
[junit4] 2> 295366 INFO (jetty-launcher-104-thread-1) [n:127.0.0.1:45743_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/.
[junit4] 2> 296037 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 0x15fd55d48310007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 296120 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 296121 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44818/solr ready
[junit4] 2> 296156 INFO (SUITE-TestPullReplica-seed#[F0E873C7465A2454]-worker) [ ] o.a.s.c.TestPullReplica Using legacyCloud?: false
[junit4] 2> 296852 INFO (qtp329021367-582) [n:127.0.0.1:35285_solr ] 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> 296861 INFO (qtp329021367-582) [n:127.0.0.1:35285_solr ] 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=9
[junit4] 2> 297028 INFO (TEST-TestPullReplica.testCreateDelete-seed#[F0E873C7465A2454]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateDelete {seed=[F0E873C7465A2454:EBF8828BB0AADC64]}
[junit4] 2> 297362 INFO (OverseerThreadFactory-357-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.CreateCollectionCmd Create collection pull_replica_test_create_delete
[junit4] 2> 297399 WARN (OverseerThreadFactory-357-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 4 on collection pull_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> 297812 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35285/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297846 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45743/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297848 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35285/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297849 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"pull_replica_test_create_delete_shard1_replica_p4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45743/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297863 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_n5",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35285/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297865 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45743/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297865 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p7",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:35285/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 297882 INFO (OverseerStateUpdate-99032313445285892-127.0.0.1:35285_solr-n_0000000000) [n:127.0.0.1:35285_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"pull_replica_test_create_delete",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"pull_replica_test_create_delete_shard2_replica_p10",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45743/solr",
[junit4] 2> "type":"PULL",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 298250 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node11&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p3&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 298250 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 298251 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node15&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p7&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 298263 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 298559 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 298842 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node13&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_n5&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 298918 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 299171 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 299274 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node9&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p2&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 299275 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 299586 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node16&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p10&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 299587 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node12&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p4&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 299613 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node14&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_p6&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=PULL
[junit4] 2> 299683 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 299720 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 299732 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 299753 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 300068 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 300098 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 300126 INFO (zkCallback-112-thread-2-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 300130 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 300131 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 300141 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p7] Schema name=minimal
[junit4] 2> 300193 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p3] Schema name=minimal
[junit4] 2> 300209 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_n1] Schema name=minimal
[junit4] 2> 300228 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 300228 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p3' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 300229 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.core.pull_replica_test_create_delete.shard1.replica_p3' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 300229 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 300229 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p3] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/pull_replica_test_create_delete_shard1_replica_p3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/./pull_replica_test_create_delete_shard1_replica_p3/data/]
[junit4] 2> 300249 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 300249 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p7' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 300264 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.core.pull_replica_test_create_delete.shard2.replica_p7' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p7') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 300264 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 300264 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_n1' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 300264 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 300264 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p7] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/pull_replica_test_create_delete_shard2_replica_p7], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/./pull_replica_test_create_delete_shard2_replica_p7/data/]
[junit4] 2> 300265 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.core.pull_replica_test_create_delete.shard1.replica_n1' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 300265 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 300265 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/pull_replica_test_create_delete_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/./pull_replica_test_create_delete_shard1_replica_n1/data/]
[junit4] 2> 300267 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 300342 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_n5] Schema name=minimal
[junit4] 2> 300344 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 300344 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_n5' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 300358 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35285.solr.core.pull_replica_test_create_delete.shard2.replica_n5' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_n5') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 300358 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 300358 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_n5] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/pull_replica_test_create_delete_shard2_replica_n5], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node2/./pull_replica_test_create_delete_shard2_replica_n5/data/]
[junit4] 2> 300955 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 301268 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 301393 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 301414 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p4] Schema name=minimal
[junit4] 2> 301479 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 301479 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 301497 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.s.SolrIndexSearcher Opening [Searcher@10b1926f[pull_replica_test_create_delete_shard1_replica_p3] main]
[junit4] 2> 301502 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard1_replica_p2] Schema name=minimal
[junit4] 2> 301504 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 301504 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p2' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 301540 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 301550 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 301558 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.core.pull_replica_test_create_delete.shard1.replica_p2' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 301558 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 301558 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/pull_replica_test_create_delete_shard1_replica_p2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/./pull_replica_test_create_delete_shard1_replica_p2/data/]
[junit4] 2> 301561 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 301561 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard1_replica_p4' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 301561 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.core.pull_replica_test_create_delete.shard1.replica_p4' (registry 'solr.core.pull_replica_test_create_delete.shard1.replica_p4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 301561 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 301562 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard1_replica_p4] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/pull_replica_test_create_delete_shard1_replica_p4], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/./pull_replica_test_create_delete_shard1_replica_p4/data/]
[junit4] 2> 301647 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 301706 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 301794 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p3 starting background replication from leader
[junit4] 2> 301795 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 301812 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p6] Schema name=minimal
[junit4] 2> 302001 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 302001 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p6' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 302018 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.core.pull_replica_test_create_delete.shard2.replica_p6' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 302018 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 302018 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p6] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/pull_replica_test_create_delete_shard2_replica_p6], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/./pull_replica_test_create_delete_shard2_replica_p6/data/]
[junit4] 2> 302055 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.s.IndexSchema [pull_replica_test_create_delete_shard2_replica_p10] Schema name=minimal
[junit4] 2> 302402 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 302402 INFO (qtp329021367-581) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 302423 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 302423 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.CoreContainer Creating SolrCore 'pull_replica_test_create_delete_shard2_replica_p10' using configuration from collection pull_replica_test_create_delete, trusted=true
[junit4] 2> 302423 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45743.solr.core.pull_replica_test_create_delete.shard2.replica_p10' (registry 'solr.core.pull_replica_test_create_delete.shard2.replica_p10') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e6c5bba
[junit4] 2> 302423 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 302423 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.SolrCore [[pull_replica_test_create_delete_shard2_replica_p10] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/pull_replica_test_create_delete_shard2_replica_p10], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.cloud.TestPullReplica_F0E873C7465A2454-001/tempDir-001/node1/./pull_replica_test_create_delete_shard2_replica_p10/data/]
[junit4] 2> 302436 INFO (searcherExecutor-362-thread-1-processing-n:127.0.0.1:35285_solr x:pull_replica_test_create_delete_shard1_replica_p3 s:shard1 c:pull_replica_test_create_delete r:core_node11) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node11 x:pull_replica_test_create_delete_shard1_replica_p3] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p3] Registered new searcher Searcher@10b1926f[pull_replica_test_create_delete_shard1_replica_p3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 302879 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 302879 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 302893 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.s.SolrIndexSearcher Opening [Searcher@59886f81[pull_replica_test_create_delete_shard2_replica_p7] main]
[junit4] 2> 302896 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 302896 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 302898 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 302941 INFO (searcherExecutor-363-thread-1-processing-n:127.0.0.1:35285_solr x:pull_replica_test_create_delete_shard2_replica_p7 s:shard2 c:pull_replica_test_create_delete r:core_node15) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_p7] Registered new searcher Searcher@59886f81[pull_replica_test_create_delete_shard2_replica_p7] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 302950 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.ZkController pull_replica_test_create_delete_shard2_replica_p7 starting background replication from leader
[junit4] 2> 302950 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 303152 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 303152 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 303153 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 303153 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 303154 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@66bf0f07[pull_replica_test_create_delete_shard1_replica_n1] main]
[junit4] 2> 303082 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 303168 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 303205 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 303205 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 303287 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 303287 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 303289 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.s.SolrIndexSearcher Opening [Searcher@3a479c2e[pull_replica_test_create_delete_shard2_replica_n5] main]
[junit4] 2> 303298 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303298 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584517028332437504
[junit4] 2> 303334 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 303334 INFO (qtp329021367-583) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303372 INFO (searcherExecutor-364-thread-1-processing-n:127.0.0.1:35285_solr x:pull_replica_test_create_delete_shard1_replica_n1 s:shard1 c:pull_replica_test_create_delete r:core_node8) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_n1] Registered new searcher Searcher@66bf0f07[pull_replica_test_create_delete_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 303372 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 303373 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 303373 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303373 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584517028411080704
[junit4] 2> 303428 INFO (searcherExecutor-365-thread-1-processing-n:127.0.0.1:35285_solr x:pull_replica_test_create_delete_shard2_replica_n5 s:shard2 c:pull_replica_test_create_delete r:core_node13) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_n5] Registered new searcher Searcher@3a479c2e[pull_replica_test_create_delete_shard2_replica_n5] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard1_replica_n1/
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard1_replica_n1/ has no replicas
[junit4] 2> 303447 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 303463 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 303464 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 303464 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard2_replica_n5/
[junit4] 2> 303464 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 303464 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.SyncStrategy https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard2_replica_n5/ has no replicas
[junit4] 2> 303464 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 303482 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard1_replica_n1/ shard1
[junit4] 2> 303484 INFO (zkCallback-112-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303513 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303513 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303537 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard2_replica_n5/ shard2
[junit4] 2> 303681 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 303681 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 303697 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.s.SolrIndexSearcher Opening [Searcher@6c74872[pull_replica_test_create_delete_shard1_replica_p4] main]
[junit4] 2> 303703 INFO (zkCallback-112-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303709 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303709 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303717 INFO (indexFetcher-388-thread-1) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node15 x:pull_replica_test_create_delete_shard2_replica_p7] o.a.s.h.IndexFetcher Replica core_node13 is leader but it's state is down, skipping replication
[junit4] 2> 303754 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 303754 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 303770 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 303770 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 303772 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.s.SolrIndexSearcher Opening [Searcher@7dfd33a[pull_replica_test_create_delete_shard1_replica_p2] main]
[junit4] 2> 303829 INFO (qtp329021367-576) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard1 r:core_node8 x:pull_replica_test_create_delete_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_n1&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=5566
[junit4] 2> 303843 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 303843 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 303843 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 303844 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303844 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 303845 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303846 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p4 starting background replication from leader
[junit4] 2> 303846 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 303918 INFO (searcherExecutor-371-thread-1-processing-n:127.0.0.1:45743_solr x:pull_replica_test_create_delete_shard1_replica_p4 s:shard1 c:pull_replica_test_create_delete r:core_node12) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p4] Registered new searcher Searcher@6c74872[pull_replica_test_create_delete_shard1_replica_p4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 303936 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 303936 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303937 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 303937 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 303939 INFO (zkCallback-112-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303940 INFO (qtp1594860229-574) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node12&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard1_replica_p4&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard1&wt=javabin&version=2&replicaType=PULL} status=0 QTime=4352
[junit4] 2> 303945 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303945 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 303955 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.s.SolrIndexSearcher Opening [Searcher@4be1c047[pull_replica_test_create_delete_shard2_replica_p10] main]
[junit4] 2> 303956 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 303956 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 303956 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 303965 INFO (qtp329021367-638) [n:127.0.0.1:35285_solr c:pull_replica_test_create_delete s:shard2 r:core_node13 x:pull_replica_test_create_delete_shard2_replica_n5] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node13&collection.configName=conf&newCollection=true&name=pull_replica_test_create_delete_shard2_replica_n5&action=CREATE&numShards=2&collection=pull_replica_test_create_delete&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=5123
[junit4] 2> 303968 INFO (searcherExecutor-370-thread-1-processing-n:127.0.0.1:45743_solr x:pull_replica_test_create_delete_shard1_replica_p2 s:shard1 c:pull_replica_test_create_delete r:core_node9) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard1_replica_p2] Registered new searcher Searcher@7dfd33a[pull_replica_test_create_delete_shard1_replica_p2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 303968 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.ZkController pull_replica_test_create_delete_shard1_replica_p2 starting background replication from leader
[junit4] 2> 303969 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 304027 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.ZkController pull_replica_test_create_delete_shard2_replica_p10 starting background replication from leader
[junit4] 2> 304027 INFO (qtp1594860229-573) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 303937 INFO (indexFetcher-397-thread-1) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node12 x:pull_replica_test_create_delete_shard1_replica_p4] o.a.s.h.IndexFetcher Replica core_node8 is leader but it's state is down, skipping replication
[junit4] 2> 304028 INFO (searcherExecutor-377-thread-1-processing-n:127.0.0.1:45743_solr x:pull_replica_test_create_delete_shard2_replica_p10 s:shard2 c:pull_replica_test_create_delete r:core_node16) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node16 x:pull_replica_test_create_delete_shard2_replica_p10] o.a.s.c.SolrCore [pull_replica_test_create_delete_shard2_replica_p10] Registered new searcher Searcher@4be1c047[pull_replica_test_create_delete_shard2_replica_p10] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 304063 INFO (zkCallback-112-thread-1-processing-n:127.0.0.1:35285_solr) [n:127.0.0.1:35285_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 304066 INFO (zkCallback-116-thread-2-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 304066 INFO (zkCallback-116-thread-1-processing-n:127.0.0.1:45743_solr) [n:127.0.0.1:45743_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/pull_replica_test_create_delete/state.json] for collection [pull_replica_test_create_delete] has occurred - updating... (live nodes size: [2])
[junit4] 2> 304087 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 304087 INFO (qtp1594860229-570) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 304088 INFO (indexFetcher-402-thread-1) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard1 r:core_node9 x:pull_replica_test_create_delete_shard1_replica_p2] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:35285/solr/pull_replica_test_create_delete_shard1_replica_n1/
[junit4] 2> 304139 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 304139 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_shard2_replica_p6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 304175 INFO (qtp1594860229-567) [n:127.0.0.1:45743_solr c:pull_replica_test_create_delete s:shard2 r:core_node14 x:pull_replica_test_create_delete_
[...truncated too long message...]
collection2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@27b91302: rootName = null, domain = solr.core.collection2, service url = null, agent id = null] for registry solr.core.collection2 / com.codahale.metrics.MetricRegistry@26381cd3
[junit4] 2> 3188947 INFO (TEST-TestLazyCores.testLazySearch-seed#[F0E873C7465A2454]) [ x:collection4] o.a.s.SolrTestCaseJ4 ###Ending testLazySearch
[junit4] 2> 3188947 INFO (SUITE-TestLazyCores-seed#[F0E873C7465A2454]-worker) [ x:collection4] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 3188947 INFO (SUITE-TestLazyCores-seed#[F0E873C7465A2454]-worker) [ x:collection4] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1809446273
[junit4] 2> 3188947 INFO (SUITE-TestLazyCores-seed#[F0E873C7465A2454]-worker) [ x:collection4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 3188947 INFO (SUITE-TestLazyCores-seed#[F0E873C7465A2454]-worker) [ x:collection4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 3188947 INFO (SUITE-TestLazyCores-seed#[F0E873C7465A2454]-worker) [ x:collection4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.core.TestLazyCores_F0E873C7465A2454-001
[junit4] 2> Nov 19, 2017 6:27:58 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Nov 19, 2017 6:28:18 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores:
[junit4] 2> 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Nov 19, 2017 6:28:18 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
[junit4] 2> Nov 19, 2017 6:28:21 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {v_t=PostingsFormat(name=LuceneVarGapDocFreqInterval), id=PostingsFormat(name=LuceneVarGapDocFreqInterval), v_s=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), v_f=BlockTreeOrds(blocksize=128)}, docValues:{}, maxPointsInLeafNode=396, maxMBSortInHeap=5.062073501111163, sim=RandomSimilarity(queryNorm=true): {}, locale=en-GB, timezone=Europe/Luxembourg
[junit4] 2> NOTE: Linux 4.4.0-83-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=2,free=300814712,total=530579456
[junit4] 2> NOTE: All tests run in this JVM: [TriLevelCompositeIdRoutingTest, SuggesterFSTTest, OverseerRolesTest, TestAnalyzedSuggestions, SOLR749Test, ZkSolrClientTest, TestHighFrequencyDictionaryFactory, TestJsonFacets, TestInitQParser, NotRequiredUniqueKeyTest, TestDeleteCollectionOnDownNodes, TestRetrieveFieldsOptimizer, MBeansHandlerTest, HdfsDirectoryFactoryTest, WrapperMergePolicyFactoryTest, RegexBoostProcessorTest, DocValuesMultiTest, TestCloudRecovery, TestSimpleTrackingShardHandler, TestStressInPlaceUpdates, TestAddFieldRealTimeGet, SuggestComponentContextFilterQueryTest, SynonymTokenizerTest, TestPrepRecovery, TestLegacyFieldReuse, SolrSlf4jReporterTest, TestLockTree, TestLuceneMatchVersion, SimpleMLTQParserTest, PreAnalyzedFieldTest, TestStressLucene, TestIntervalFaceting, SuggesterTSTTest, LukeRequestHandlerTest, ConvertedLegacyTest, BasicAuthStandaloneTest, TermVectorComponentDistributedTest, MultiThreadedOCPTest, TestConfigReload, ConjunctionSolrSpellCheckerTest, ZkCLITest, SpatialRPTFieldTypeTest, TestRandomFlRTGCloud, ReplicaListTransformerTest, SolrMetricReporterTest, ZkStateReaderTest, TestAtomicUpdateErrorCases, MetricsConfigTest, CdcrRequestHandlerTest, BadIndexSchemaTest, BooleanFieldTest, TestStressRecovery, TestDocTermOrds, NumberUtilsTest, TestLeaderElectionZkExpiry, TestNonDefinedSimilarityFactory, PingRequestHandlerTest, PrimUtilsTest, CloudExitableDirectoryReaderTest, TestQueryWrapperFilter, TestManagedSynonymFilterFactory, SignatureUpdateProcessorFactoryTest, HdfsCollectionsAPIDistributedZkTest, TestSQLHandlerNonCloud, BinaryUpdateRequestHandlerTest, TestDocSet, FullHLLTest, TestPushWriter, SampleTest, DeleteShardTest, MergeStrategyTest, CoreSorterTest, ShowFileRequestHandlerTest, TestConfigSets, AnalyticsQueryTest, TestConfigSetsAPIExclusivity, TemplateUpdateProcessorTest, DateRangeFieldTest, TestJettySolrRunner, TestSerializedLuceneMatchVersion, ManagedSchemaRoundRobinCloudTest, DistributedExpandComponentTest, TestSolr4Spatial2, TestSurroundQueryParser, TestSearcherReuse, RollingRestartTest, TestReqParamsAPI, BigEndianAscendingWordSerializerTest, CollectionTooManyReplicasTest, TestFieldTypeCollectionResource, TestManagedSchema, TestSolrXml, RegexBytesRefFilterTest, TestOmitPositions, DistributedVersionInfoTest, DistributedIntervalFacetingTest, ClassificationUpdateProcessorFactoryTest, BufferStoreTest, TestWriterPerf, ClusterStateUpdateTest, HdfsRecoveryZkTest, TestExceedMaxTermLength, TriggerIntegrationTest, TestLazyCores]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestLazyCores -Dtests.seed=F0E873C7465A2454 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=en-GB -Dtests.timezone=Europe/Luxembourg -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | TestLazyCores (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores:
[junit4] > 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=8870, name=searcherExecutor-3806-thread-1, state=WAITING, group=TGRP-TestLazyCores]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at __randomizedtesting.SeedInfo.seed([F0E873C7465A2454]:0)
[junit4] Completed [322/749 (2!)] on J1 in 52.35s, 9 tests, 3 errors <<< FAILURES!
[...truncated 48652 lines...]