Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-7.x/186/

1 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([98EFF12E41176E53:D1F9059A23ACFA05]: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:542)
        at 
org.apache.solr.cloud.TestPullReplica.waitForNumDocsInAllReplicas(TestPullReplica.java:533)
        at 
org.apache.solr.cloud.TestPullReplica.doTestNoLeader(TestPullReplica.java:403)
        at 
org.apache.solr.cloud.TestPullReplica.testKillLeader(TestPullReplica.java:309)
        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:1742)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
        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:944)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:830)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:880)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:891)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 13530 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestPullReplica
   [junit4]   2> 1425066 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/init-core-data-001
   [junit4]   2> 1425067 WARN  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7
   [junit4]   2> 1425067 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 1425070 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1425071 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001
   [junit4]   2> 1425071 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1425072 INFO  (Thread-2568) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1425072 INFO  (Thread-2568) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1425078 ERROR (Thread-2568) [    ] 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> 1425172 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:33929
   [junit4]   2> 1425181 INFO  (zkConnectionManagerCallback-3090-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425190 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: 
d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 1425191 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1425191 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1425191 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 1425191 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: 
d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 1425192 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@d0d9715{/solr,null,AVAILABLE}
   [junit4]   2> 1425192 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1425192 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1425193 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 1425193 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1dbaced4{/solr,null,AVAILABLE}
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@577ff9b3{SSL,[ssl, 
http/1.1]}{127.0.0.1:46387}
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.e.j.s.Server Started @1425250ms
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=46387}
   [junit4]   2> 1425194 ERROR (jetty-launcher-3087-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter Using logger factory 
org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.6.0
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1425194 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-10-14T14:42:27.891Z
   [junit4]   2> 1425196 INFO  (zkConnectionManagerCallback-3092-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425197 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1425202 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@37d5e488{SSL,[ssl, 
http/1.1]}{127.0.0.1:42257}
   [junit4]   2> 1425202 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.e.j.s.Server Started @1425259ms
   [junit4]   2> 1425202 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42257}
   [junit4]   2> 1425202 ERROR (jetty-launcher-3087-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1425202 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter Using logger factory 
org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1425203 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.6.0
   [junit4]   2> 1425203 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1425203 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1425203 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-10-14T14:42:27.900Z
   [junit4]   2> 1425206 INFO  (zkConnectionManagerCallback-3094-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425207 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1425327 INFO  (jetty-launcher-3087-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33929/solr
   [junit4]   2> 1425328 INFO  (zkConnectionManagerCallback-3098-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425331 INFO  (zkConnectionManagerCallback-3100-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425352 INFO  (jetty-launcher-3087-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33929/solr
   [junit4]   2> 1425353 INFO  (zkConnectionManagerCallback-3106-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425356 INFO  (zkConnectionManagerCallback-3108-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425371 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:42257_solr
   [junit4]   2> 1425373 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer Overseer 
(id=72101040225386502-127.0.0.1:42257_solr-n_0000000000) starting
   [junit4]   2> 1425383 INFO  (zkConnectionManagerCallback-3115-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425386 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster 
at 127.0.0.1:33929/solr ready
   [junit4]   2> 1425388 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and 
.scheduled_maintenance triggers
   [junit4]   2> 1425390 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode 
version 1
   [junit4]   2> 1425390 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, 
lastZnodeVersion -1
   [junit4]   2> 1425390 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto 
znodeVersion 1
   [junit4]   2> 1425395 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer Starting to work on the main 
queue : 127.0.0.1:42257_solr
   [junit4]   2> 1425395 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42257_solr
   [junit4]   2> 1425408 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1425443 INFO  (zkCallback-3114-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1425445 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system 
collection, keeping metrics history in memory.
   [junit4]   2> 1425447 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial 
livenodes: [127.0.0.1:42257_solr]
   [junit4]   2> 1425447 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1425448 DEBUG 
(OverseerAutoScalingTriggerThread-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, 
lastZnodeVersion 1
   [junit4]   2> 1425448 DEBUG (ScheduledTrigger-5493-thread-1) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 1
   [junit4]   2> 1425488 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1425491 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42257.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425494 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating 
transient cache for 2147483647 transient cores
   [junit4]   2> 1425494 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:46387_solr
   [junit4]   2> 1425495 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:46387_solr"} current state version: 0
   [junit4]   2> 1425496 INFO  (zkCallback-3107-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1425496 INFO  (zkCallback-3114-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1425502 INFO  (zkCallback-3099-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1425505 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42257.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425505 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42257.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425507 INFO  (jetty-launcher-3087-thread-2) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node1/.
   [junit4]   2> 1425523 INFO  (zkConnectionManagerCallback-3121-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425524 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1425525 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster 
at 127.0.0.1:33929/solr ready
   [junit4]   2> 1425526 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system 
collection, keeping metrics history in memory.
   [junit4]   2> 1425570 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46387.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425585 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46387.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425585 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46387.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1425587 INFO  (jetty-launcher-3087-thread-1) 
[n:127.0.0.1:46387_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node2/.
   [junit4]   2> 1425620 INFO  (zkConnectionManagerCallback-3124-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425624 INFO  (zkConnectionManagerCallback-3129-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1425625 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1425626 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33929/solr ready
   [junit4]   2> 1425630 INFO  
(SUITE-TestPullReplica-seed#[98EFF12E41176E53]-worker) [    ] 
o.a.s.c.TestPullReplica Using legacyCloud?: false
   [junit4]   2> 1425662 INFO  (qtp356500632-12872) [n:127.0.0.1:42257_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> 1425663 INFO  (qtp356500632-12872) [n:127.0.0.1:42257_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=1
   [junit4]   2> 1425942 INFO  
(TEST-TestPullReplica.testAddDocs-seed#[98EFF12E41176E53]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testAddDocs
   [junit4]   2> 1425947 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
pullReplicas=3&collection.configName=conf&maxShardsPerNode=100&name=pull_replica_test_add_docs&nrtReplicas=1&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1425950 INFO  
(OverseerThreadFactory-5495-thread-1-processing-n:127.0.0.1:42257_solr) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection 
pull_replica_test_add_docs
   [junit4]   2> 1425955 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "name":"pull_replica_test_add_docs",
   [junit4]   2>   "fromApi":"true",
   [junit4]   2>   "collection.configName":"conf",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "maxShardsPerNode":"100",
   [junit4]   2>   "pullReplicas":"3",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "nrtReplicas":"1",
   [junit4]   2>   "stateFormat":"2",
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "operation":"create"} current state version: 0
   [junit4]   2> 1426055 WARN  
(OverseerThreadFactory-5495-thread-1-processing-n:127.0.0.1:42257_solr) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.a.c.CreateCollectionCmd Specified number 
of replicas of 4 on collection pull_replica_test_add_docs 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> 1426068 INFO  (qtp356500632-12871) [n:127.0.0.1:42257_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 1426107 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 1426113 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1426114 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1426117 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, 
message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1426117 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1426121 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 3, 
message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p5",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1426121 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p5",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1426125 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 4, 
message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p6",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 1426125 INFO  
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p6",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1426338 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr    
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation 
core create command 
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_n1&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1426338 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr    
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.h.a.CoreAdminOperation 
core create command 
qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_p5&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 1426338 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr    
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.h.a.CoreAdminOperation 
core create command 
qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_p2&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 1426339 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr    
x:pull_replica_test_add_docs_shard1_replica_p5] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1426343 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr    
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.h.a.CoreAdminOperation 
core create command 
qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_p6&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL
   [junit4]   2> 1426360 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p6",
   [junit4]   2>   "core_node_name":"core_node8",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:46387_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1426360 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:46387_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1426361 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 4, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:42257_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1426361 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 4, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p5",
   [junit4]   2>   "core_node_name":"core_node7",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:42257_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1426457 DEBUG (ScheduledTrigger-5493-thread-3) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 2
   [junit4]   2> 1427373 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.6.0
   [junit4]   2> 1427373 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.6.0
   [junit4]   2> 1427380 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.6.0
   [junit4]   2> 1427380 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.6.0
   [junit4]   2> 1427404 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.s.IndexSchema 
[pull_replica_test_add_docs_shard1_replica_p2] Schema name=minimal
   [junit4]   2> 1427405 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.s.IndexSchema 
[pull_replica_test_add_docs_shard1_replica_p6] Schema name=minimal
   [junit4]   2> 1427405 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.s.IndexSchema 
[pull_replica_test_add_docs_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 1427407 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.s.IndexSchema 
[pull_replica_test_add_docs_shard1_replica_p5] Schema name=minimal
   [junit4]   2> 1427408 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1427408 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1427408 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.CoreContainer Creating 
SolrCore 'pull_replica_test_add_docs_shard1_replica_p2' using configuration 
from collection pull_replica_test_add_docs, trusted=true
   [junit4]   2> 1427408 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.c.CoreContainer Creating 
SolrCore 'pull_replica_test_add_docs_shard1_replica_p6' using configuration 
from collection pull_replica_test_add_docs, trusted=true
   [junit4]   2> 1427408 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1427408 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.CoreContainer Creating 
SolrCore 'pull_replica_test_add_docs_shard1_replica_n1' using configuration 
from collection pull_replica_test_add_docs, trusted=true
   [junit4]   2> 1427409 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 
'solr_46387.solr.core.pull_replica_test_add_docs.shard1.replica_p6' (registry 
'solr.core.pull_replica_test_add_docs.shard1.replica_p6') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1427409 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 
'solr_46387.solr.core.pull_replica_test_add_docs.shard1.replica_n1' (registry 
'solr.core.pull_replica_test_add_docs.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1427409 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.c.SolrCore 
[[pull_replica_test_add_docs_shard1_replica_p6] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node2/pull_replica_test_add_docs_shard1_replica_p6],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node2/./pull_replica_test_add_docs_shard1_replica_p6/data/]
   [junit4]   2> 1427409 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.SolrCore 
[[pull_replica_test_add_docs_shard1_replica_n1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node2/pull_replica_test_add_docs_shard1_replica_n1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node2/./pull_replica_test_add_docs_shard1_replica_n1/data/]
   [junit4]   2> 1427409 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1427410 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.CoreContainer Creating 
SolrCore 'pull_replica_test_add_docs_shard1_replica_p5' using configuration 
from collection pull_replica_test_add_docs, trusted=true
   [junit4]   2> 1427410 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 
'solr_42257.solr.core.pull_replica_test_add_docs.shard1.replica_p5' (registry 
'solr.core.pull_replica_test_add_docs.shard1.replica_p5') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1427410 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.SolrCore 
[[pull_replica_test_add_docs_shard1_replica_p5] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node1/pull_replica_test_add_docs_shard1_replica_p5],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node1/./pull_replica_test_add_docs_shard1_replica_p5/data/]
   [junit4]   2> 1427413 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 
'solr_42257.solr.core.pull_replica_test_add_docs.shard1.replica_p2' (registry 
'solr.core.pull_replica_test_add_docs.shard1.replica_p2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13190fee
   [junit4]   2> 1427413 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.SolrCore 
[[pull_replica_test_add_docs_shard1_replica_p2] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node1/pull_replica_test_add_docs_shard1_replica_p2],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplica_98EFF12E41176E53-001/tempDir-001/node1/./pull_replica_test_add_docs_shard1_replica_p2/data/]
   [junit4]   2> 1427458 DEBUG (ScheduledTrigger-5493-thread-4) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 2
   [junit4]   2> 1427501 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1427501 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1427502 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.UpdateHandler Using 
UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1427502 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.UpdateLog Initializing 
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1427503 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1427503 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1427504 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@23836c8[pull_replica_test_add_docs_shard1_replica_p2] main]
   [junit4]   2> 1427505 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1427506 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1427508 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1427508 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1427508 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427509 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@b5c813d[pull_replica_test_add_docs_shard1_replica_p6] main]
   [junit4]   2> 1427509 INFO  
(searcherExecutor-5504-thread-1-processing-n:127.0.0.1:42257_solr 
x:pull_replica_test_add_docs_shard1_replica_p2 c:pull_replica_test_add_docs 
s:shard1 r:core_node4) [n:127.0.0.1:42257_solr c:pull_replica_test_add_docs 
s:shard1 r:core_node4 x:pull_replica_test_add_docs_shard1_replica_p2] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_p2] Registered new 
searcher Searcher@23836c8[pull_replica_test_add_docs_shard1_replica_p2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1427511 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1427511 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1427511 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@1f1ff9ca[pull_replica_test_add_docs_shard1_replica_n1] main]
   [junit4]   2> 1427512 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427514 INFO  
(searcherExecutor-5505-thread-1-processing-n:127.0.0.1:46387_solr 
x:pull_replica_test_add_docs_shard1_replica_p6 c:pull_replica_test_add_docs 
s:shard1 r:core_node8) [n:127.0.0.1:46387_solr c:pull_replica_test_add_docs 
s:shard1 r:core_node8 x:pull_replica_test_add_docs_shard1_replica_p6] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_p6] Registered new 
searcher Searcher@b5c813d[pull_replica_test_add_docs_shard1_replica_p6] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1427515 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1427515 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1427516 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1427516 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1427518 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427518 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.UpdateLog Could not 
find max version in index or recent updates, using new clock 1614312269639843840
   [junit4]   2> 1427519 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@37cfeefc[pull_replica_test_add_docs_shard1_replica_p5] main]
   [junit4]   2> 1427525 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.c.ZkController 
pull_replica_test_add_docs_shard1_replica_p6 starting background replication 
from leader
   [junit4]   2> 1427525 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.c.ReplicateFromLeader 
Will start replication from leader with poll interval: 00:00:03
   [junit4]   2> 1427525 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.ZkController 
pull_replica_test_add_docs_shard1_replica_p2 starting background replication 
from leader
   [junit4]   2> 1427525 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.ReplicateFromLeader 
Will start replication from leader with poll interval: 00:00:03
   [junit4]   2> 1427526 INFO  
(searcherExecutor-5506-thread-1-processing-n:127.0.0.1:46387_solr 
x:pull_replica_test_add_docs_shard1_replica_n1 c:pull_replica_test_add_docs 
s:shard1 r:core_node3) [n:127.0.0.1:46387_solr c:pull_replica_test_add_docs 
s:shard1 r:core_node3 x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_n1] Registered new 
searcher Searcher@1f1ff9ca[pull_replica_test_add_docs_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1427527 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1427528 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.h.ReplicationHandler Poll 
scheduled at an interval of 3000ms
   [junit4]   2> 1427528 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.h.ReplicationHandler Poll 
scheduled at an interval of 3000ms
   [junit4]   2> 1427528 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427528 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427528 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful 
update of terms at /collections/pull_replica_test_add_docs/terms/shard1 to 
Terms{values={core_node3=0}, version=0}
   [junit4]   2> 1427535 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1427536 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427537 INFO  
(searcherExecutor-5507-thread-1-processing-n:127.0.0.1:42257_solr 
x:pull_replica_test_add_docs_shard1_replica_p5 c:pull_replica_test_add_docs 
s:shard1 r:core_node7) [n:127.0.0.1:42257_solr c:pull_replica_test_add_docs 
s:shard1 r:core_node7 x:pull_replica_test_add_docs_shard1_replica_p5] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_p5] Registered new 
searcher Searcher@37cfeefc[pull_replica_test_add_docs_shard1_replica_p5] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1427546 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.ZkController 
pull_replica_test_add_docs_shard1_replica_p5 starting background replication 
from leader
   [junit4]   2> 1427547 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.ReplicateFromLeader 
Will start replication from leader with poll interval: 00:00:03
   [junit4]   2> 1427548 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.h.ReplicationHandler Poll 
scheduled at an interval of 3000ms
   [junit4]   2> 1427549 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.h.ReplicationHandler 
Commits will be reserved for 10000ms.
   [junit4]   2> 1427551 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs"} current state 
version: 0
   [junit4]   2> 1427552 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1427552 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1427552 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.SyncStrategy Sync 
replicas to 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/
   [junit4]   2> 1427552 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.SyncStrategy Sync 
Success - now sync replicas to me
   [junit4]   2> 1427553 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.SyncStrategy 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/ has 
no replicas
   [junit4]   2> 1427553 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1427557 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/ 
shard1
   [junit4]   2> 1427558 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, 
message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_n1",
   [junit4]   2>   "state":"active"} current state version: 0
   [junit4]   2> 1427660 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.ZkController I am the 
leader, no recovery necessary
   [junit4]   2> 1427667 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:46387_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1427667 INFO  (qtp1048132203-12881) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] 
webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_n1&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1329
   [junit4]   2> 1427686 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Replica core_node3 is leader but it's state is down, 
skipping replication
   [junit4]   2> 1427768 INFO  (zkCallback-3099-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/pull_replica_test_add_docs/state.json] for collection 
[pull_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1428458 DEBUG (ScheduledTrigger-5493-thread-3) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 2
   [junit4]   2> 1428547 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p6",
   [junit4]   2>   "core_node_name":"core_node8",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:46387/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:46387_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1428547 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node8 
x:pull_replica_test_add_docs_shard1_replica_p6] 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_add_docs_shard1_replica_p6&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL}
 status=0 QTime=2203
   [junit4]   2> 1428549 INFO  (qtp356500632-12873) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.s.HttpSolrCall [admin] 
webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_p2&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL}
 status=0 QTime=2211
   [junit4]   2> 1428549 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:42257_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1428556 DEBUG 
(OverseerStateUpdate-72101040225386502-127.0.0.1:42257_solr-n_0000000000) 
[n:127.0.0.1:42257_solr    ] o.a.s.c.Overseer processMessage: queueSize: 3, 
message = {
   [junit4]   2>   "core":"pull_replica_test_add_docs_shard1_replica_p5",
   [junit4]   2>   "core_node_name":"core_node7",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:42257/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:42257_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"pull_replica_test_add_docs",
   [junit4]   2>   "type":"PULL",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 1428556 INFO  (qtp356500632-12867) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.s.HttpSolrCall [admin] 
webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=pull_replica_test_add_docs_shard1_replica_p5&action=CREATE&numShards=1&collection=pull_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=PULL}
 status=0 QTime=2218
   [junit4]   2> 1428566 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr    
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 
30 seconds. Check all shard replicas
   [junit4]   2> 1428657 INFO  (zkCallback-3099-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/pull_replica_test_add_docs/state.json] for collection 
[pull_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1428657 INFO  (zkCallback-3107-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/pull_replica_test_add_docs/state.json] for collection 
[pull_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 1428858 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher Updated masterUrl to 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/
   [junit4]   2> 1428869 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.h.IndexFetcher New index in Master. Deleting mine...
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1428870 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@24229f67 commitCommandVersion:0
   [junit4]   2> 1428887 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6bd87fa8[pull_replica_test_add_docs_shard1_replica_p5] main]
   [junit4]   2> 1428887 INFO  (indexFetcher-5526-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1428889 INFO  (searcherExecutor-5507-thread-1) [    ] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_p5] Registered new 
searcher Searcher@6bd87fa8[pull_replica_test_add_docs_shard1_replica_p5] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1429459 DEBUG (ScheduledTrigger-5493-thread-1) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 2
   [junit4]   2> 1429567 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={pullReplicas=3&collection.configName=conf&maxShardsPerNode=100&name=pull_replica_test_add_docs&nrtReplicas=1&action=CREATE&numShards=1&tlogReplicas=0&wt=javabin&version=2}
 status=0 QTime=3619
   [junit4]   2> 1429596 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful 
update of terms at /collections/pull_replica_test_add_docs/terms/shard1 to 
Terms{values={core_node3=1}, version=1}
   [junit4]   2> 1429596 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.u.p.LogUpdateProcessorFactory 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/update 
params={wt=javabin&version=2}{add=[1 (1614312271805153280)]} 0 13
   [junit4]   2> 1429607 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 
start 
commit{_version_=1614312271830319104,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1429607 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling 
setCommitData with IW:org.apache.solr.update.SolrIndexWriter@141cfe7f 
commitCommandVersion:1614312271830319104
   [junit4]   2> 1429627 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@3229ce74[pull_replica_test_add_docs_shard1_replica_n1] main]
   [junit4]   2> 1429627 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 1429629 INFO  
(searcherExecutor-5506-thread-1-processing-n:127.0.0.1:46387_solr 
x:pull_replica_test_add_docs_shard1_replica_n1 c:pull_replica_test_add_docs 
s:shard1 r:core_node3) [n:127.0.0.1:46387_solr c:pull_replica_test_add_docs 
s:shard1 r:core_node3 x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_n1] Registered new 
searcher Searcher@3229ce74[pull_replica_test_add_docs_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.6.0):C1)))}
   [junit4]   2> 1429629 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] 
o.a.s.u.p.LogUpdateProcessorFactory 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/update 
params={_stateVer_=pull_replica_test_add_docs:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 23
   [junit4]   2> 1429636 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
   [junit4]   2> 1429641 INFO  (qtp356500632-12869) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1429742 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1429844 INFO  (qtp356500632-12869) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1429944 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1429953 INFO  
(OverseerCollectionConfigSetProcessor-72101040225386502-127.0.0.1:42257_solr-n_0000000000)
 [n:127.0.0.1:42257_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 1430046 INFO  (qtp356500632-12869) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1430147 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1430208 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Updated masterUrl to 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/
   [junit4]   2> 1430208 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 1430208 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's generation: 2
   [junit4]   2> 1430208 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's version: 1539528152304
   [junit4]   2> 1430208 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 1430208 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 1430209 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 1430209 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist}
 status=0 QTime=0
   [junit4]   2> 1430210 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Number of files in latest index in master: 17
   [junit4]   2> 1430218 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting download (fullCopy=false) to 
MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@70c541a0 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@601df010; 
maxCacheMB=0.6396484375 maxMergeSizeMB=0.1298828125))
   [junit4]   2> 1430219 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430220 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.doc&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430225 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.tim&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430226 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.tip&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430227 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430228 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430229 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430229 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.dii&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430230 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Asserting_0.pos&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430231 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Asserting_0.doc&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430232 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Asserting_0.tim&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430233 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.dim&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430234 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Asserting_0.tip&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430235 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430236 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.pos&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430236 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430237 INFO  (qtp1048132203-12879) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430238 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Bytes downloaded: 2500, Bytes skipped downloading: 0
   [junit4]   2> 1430238 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.h.IndexFetcher Total time taken for download 
(fullCopy=false,bytesDownloaded=2500) : 0 secs (null bytes/sec) to 
MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@70c541a0 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@601df010; 
maxCacheMB=0.6396484375 maxMergeSizeMB=0.1298828125))
   [junit4]   2> 1430250 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 1430251 INFO  (qtp356500632-12869) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1430251 INFO  (indexFetcher-5524-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@5481e2ed[pull_replica_test_add_docs_shard1_replica_p2] main]
   [junit4]   2> 1430253 INFO  (searcherExecutor-5504-thread-1) [    ] 
o.a.s.c.SolrCore [pull_replica_test_add_docs_shard1_replica_p2] Registered new 
searcher Searcher@5481e2ed[pull_replica_test_add_docs_shard1_replica_p2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.6.0):C1)))}
   [junit4]   2> 1430352 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
   [junit4]   2> 1430365 INFO  (qtp356500632-12869) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node4 
x:pull_replica_test_add_docs_shard1_replica_p2] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p2]  webapp=/solr 
path=/admin/plugins params={qt=/admin/plugins&stats=true&wt=javabin&version=2} 
status=0 QTime=11
   [junit4]   2> 1430372 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p5]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1430459 DEBUG (ScheduledTrigger-5493-thread-3) [    ] 
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with 
currently live nodes: 2
   [junit4]   2> 1430473 INFO  (qtp356500632-12870) [n:127.0.0.1:42257_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node7 
x:pull_replica_test_add_docs_shard1_replica_p5] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_p5]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 1430527 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Last replication failed, so I'll force replication
   [junit4]   2> 1430527 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Updated masterUrl to 
https://127.0.0.1:46387/solr/pull_replica_test_add_docs_shard1_replica_n1/
   [junit4]   2> 1430530 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 
QTime=0
   [junit4]   2> 1430530 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's generation: 2
   [junit4]   2> 1430530 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Master's version: 1539528152304
   [junit4]   2> 1430530 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 1430530 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 1430530 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 1430531 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist}
 status=0 QTime=0
   [junit4]   2> 1430532 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Number of files in latest index in master: 17
   [junit4]   2> 1430532 INFO  (indexFetcher-5523-thread-1) [    ] 
o.a.s.h.IndexFetcher Starting download (fullCopy=true) to 
MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@689ddfb6 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4efefdd2; 
maxCacheMB=0.6396484375 maxMergeSizeMB=0.1298828125))
   [junit4]   2> 1430532 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430534 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.doc&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430535 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.tim&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430536 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Direct_0.tip&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430537 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430538 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430539 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430540 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0.dii&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430541 INFO  (qtp1048132203-12882) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
params={generation=2&qt=/replication&file=_0_Asserting_0.pos&checksum=true&wt=filestream&command=filecontent}
 status=0 QTime=0
   [junit4]   2> 1430542 INFO  (qtp1048132203-12876) [n:127.0.0.1:46387_solr 
c:pull_replica_test_add_docs s:shard1 r:core_node3 
x:pull_replica_test_add_docs_shard1_replica_n1] o.a.s.c.S.Request 
[pull_replica_test_add_docs_shard1_replica_n1]  webapp=/solr path=/replication 
param

[...truncated too long message...]

e] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null1748950554
     [copy] Copying 239 files to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null1748950554
   [delete] Deleting directory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null1748950554

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: 
org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath]         confs: [default]
[ivy:cachepath]         found 
org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath]         found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath]         found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath]         found org.apache.httpcomponents#httpclient;4.3.6 in 
public
[ivy:cachepath]         found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath]         found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath]         found commons-codec#commons-codec;1.6 in public
[ivy:cachepath]         found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 30ms :: artifacts dl 2ms
        ---------------------------------------------------------------------
        |                  |            modules            ||   artifacts   |
        |       conf       | number| search|dwnlded|evicted|| number|dwnlded|
        ---------------------------------------------------------------------
        |      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
        ---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for 
further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 126 minutes 21 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
        at hudson.FilePath$34.hasMatch(FilePath.java:2678)
        at hudson.FilePath$34.invoke(FilePath.java:2557)
        at hudson.FilePath$34.invoke(FilePath.java:2547)
        at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
                at 
hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
                at 
hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
                at hudson.remoting.Channel.call(Channel.java:955)
                at hudson.FilePath.act(FilePath.java:1036)
                at hudson.FilePath.act(FilePath.java:1025)
                at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
                at 
hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
                at 
hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
                at 
hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
                at 
hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
                at 
hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
                at hudson.model.Build$BuildExecution.post2(Build.java:186)
                at 
hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
                at hudson.model.Run.execute(Run.java:1819)
                at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
                at 
hudson.model.ResourceController.execute(ResourceController.java:97)
                at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
        at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
        at hudson.remoting.UserRequest.perform(UserRequest.java:212)
        at hudson.remoting.UserRequest.perform(UserRequest.java:54)
        at hudson.remoting.Request$2.run(Request.java:369)
        at 
hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no 
matches found within 10000
        at hudson.FilePath.act(FilePath.java:1038)
        at hudson.FilePath.act(FilePath.java:1025)
        at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
        at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
        at 
hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
        at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
        at 
hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
        at 
hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
        at hudson.model.Build$BuildExecution.post2(Build.java:186)
        at 
hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
        at hudson.model.Run.execute(Run.java:1819)
        at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
        at hudson.model.ResourceController.execute(ResourceController.java:97)
        at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern 
"**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to