Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/420/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC

1 tests failed.
FAILED:  
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([9DAE0B00742EAE53:27A23C8F2BC6781C]:0)
        at org.junit.Assert.fail(Assert.java:92)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertNull(Assert.java:551)
        at org.junit.Assert.assertNull(Assert.java:562)
        at 
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1575)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 13695 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
   [junit4]   2> 3320281 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/init-core-data-001
   [junit4]   2> 3320281 WARN  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=30 numCloses=30
   [junit4]   2> 3320281 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 3320284 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) 
w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 3320285 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001
   [junit4]   2> 3320285 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3320285 INFO  (Thread-6063) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3320285 INFO  (Thread-6063) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3320287 ERROR (Thread-6063) [    ] 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> 3320394 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:51253
   [junit4]   2> 3320418 INFO  (zkConnectionManagerCallback-8961-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320428 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3320428 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3320430 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3320431 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3320431 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3320433 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3320433 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3320433 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3320433 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@52c673b9{/solr,null,AVAILABLE}
   [junit4]   2> 3320434 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@917b512{/solr,null,AVAILABLE}
   [junit4]   2> 3320434 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@73d0f254{HTTP/1.1,[http/1.1]}{127.0.0.1:51257}
   [junit4]   2> 3320435 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.e.j.s.Server Started @3324665ms
   [junit4]   2> 3320435 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51257}
   [junit4]   2> 3320436 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@5a9d1c97{HTTP/1.1,[http/1.1]}{127.0.0.1:51256}
   [junit4]   2> 3320436 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.e.j.s.Server Started @3324667ms
   [junit4]   2> 3320436 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51256}
   [junit4]   2> 3320436 ERROR (jetty-launcher-8958-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3320437 ERROR (jetty-launcher-8958-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:34.422Z
   [junit4]   2> 3320437 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3320438 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:34.423Z
   [junit4]   2> 3320441 INFO  (zkConnectionManagerCallback-8965-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320441 INFO  (zkConnectionManagerCallback-8964-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320442 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3320442 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3320457 INFO  (jetty-launcher-8958-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3320457 INFO  (jetty-launcher-8958-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3320459 INFO  (zkConnectionManagerCallback-8971-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320459 INFO  (zkConnectionManagerCallback-8973-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320462 INFO  
(zkConnectionManagerCallback-8975-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320462 INFO  
(zkConnectionManagerCallback-8977-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320604 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3320604 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3320605 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:51257_solr
   [junit4]   2> 3320606 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51256_solr
   [junit4]   2> 3320606 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.Overseer Overseer 
(id=99411223791009798-127.0.0.1:51257_solr-n_0000000000) starting
   [junit4]   2> 3320607 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3320607 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3320616 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 3320618 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 3320619 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:51256_solr]
   [junit4]   2> 3320619 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 3320619 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 3320620 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51257_solr
   [junit4]   2> 3320622 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3320622 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3320622 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3320623 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3320633 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 2
   [junit4]   2> 3320795 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51256.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320804 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51256.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320804 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51256.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320806 INFO  (jetty-launcher-8958-thread-1) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node1/.
   [junit4]   2> 3320808 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51257.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320814 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51257.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320814 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51257.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320815 INFO  (jetty-launcher-8958-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node2/.
   [junit4]   2> 3320853 INFO  (zkConnectionManagerCallback-8983-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320856 INFO  (zkConnectionManagerCallback-8987-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320858 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3320859 INFO  
(SUITE-TriggerIntegrationTest-seed#[9DAE0B00742EAE53]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:51253/solr ready
   [junit4]   2> 3320875 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
   [junit4]   2> 3320875 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode 
version 2
   [junit4]   2> 3320876 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 2
   [junit4]   2> 3320876 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 2
   [junit4]   2> 3320878 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3320879 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3320879 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 3320881 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3320882 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3320882 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3320882 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@5566df02{/solr,null,AVAILABLE}
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.AbstractConnector Started 
ServerConnector@3c23ffe{HTTP/1.1,[http/1.1]}{127.0.0.1:51270}
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.Server Started @3325114ms
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51270}
   [junit4]   2> 3320883 ERROR 
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging 
may be missing or incomplete.
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ 
version 7.3.0
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on 
port null
   [junit4]   2> 3320883 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3320884 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:34.869Z
   [junit4]   2> 3320885 INFO  (zkConnectionManagerCallback-8989-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320886 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3320893 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3320895 INFO  (zkConnectionManagerCallback-8993-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320897 INFO  
(zkConnectionManagerCallback-8995-thread-1-processing-n:127.0.0.1:51270_solr) 
[n:127.0.0.1:51270_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3320907 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3320910 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3320913 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51270_solr
   [junit4]   2> 3320914 INFO  (zkCallback-8986-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3320915 INFO  
(zkCallback-8994-thread-1-processing-n:127.0.0.1:51270_solr) 
[n:127.0.0.1:51270_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3320915 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3320915 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3320973 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51270.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320981 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51270.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320982 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51270.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3320983 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [n:127.0.0.1:51270_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node3/.
   [junit4]   2> 3321041 INFO  (qtp648975697-35491) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3321043 INFO  (qtp94106374-35503) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3321044 INFO  (qtp1786513822-35551) [n:127.0.0.1:51270_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3321044 DEBUG (qtp94106374-35497) [n:127.0.0.1:51257_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3321045 INFO  (qtp94106374-35497) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=5
   [junit4]   2> 3321046 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 3
   [junit4]   2> 3321047 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.AbstractConnector Stopped 
ServerConnector@3c23ffe{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 3321047 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=805325922
   [junit4]   2> 3321047 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.node, tag=null
   [junit4]   2> 3321047 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@624e0b9c: rootName = 
solr_51270, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@2ae5b6d
   [junit4]   2> 3321047 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:51270_solr, 127.0.0.1:51257_solr, 127.0.0.1:51256_solr]
   [junit4]   2> 3321047 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 3
   [junit4]   2> 3321050 INFO  
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3321051 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3321051 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 3321052 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_restore_trigger with currently live nodes: 3
   [junit4]   2> 3321054 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jvm, tag=null
   [junit4]   2> 3321054 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@34147af3: rootName = 
solr_51270, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@72ac670f
   [junit4]   2> 3321058 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jetty, tag=null
   [junit4]   2> 3321058 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@4d943ca5: rootName = 
solr_51270, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@11092637
   [junit4]   2> 3321060 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51270_solr
   [junit4]   2> 3321061 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.cluster, tag=null
   [junit4]   2> 3321061 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 3321062 INFO  
(zkCallback-8994-thread-1-processing-n:127.0.0.1:51270_solr) 
[n:127.0.0.1:51270_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3321062 INFO  (zkCallback-8986-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 3321062 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x1612dfb38c0000b, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 3321063 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@5566df02{/solr,null,UNAVAILABLE}
   [junit4]   2> 3321063 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.e.j.s.session Stopped scavenging
   [junit4]   2> 3321063 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3321063 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3322059 DEBUG (ScheduledTrigger-13432-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_restore_trigger with currently live nodes: 2
   [junit4]   2> 3322059 DEBUG (ScheduledTrigger-13432-thread-2) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 
127.0.0.1:51270_solr
   [junit4]   2> 3322576 INFO  (qtp648975697-35493) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3322577 INFO  (qtp94106374-35503) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3322577 DEBUG (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3322578 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 3322579 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 4
   [junit4]   2> 3322579 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:51257_solr, 127.0.0.1:51256_solr]
   [junit4]   2> 3322579 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 4
   [junit4]   2> 3322580 INFO  
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3322580 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Adding lost node from 
marker path: 127.0.0.1:51270_solr
   [junit4]   2> 3322581 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3322581 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_restore_trigger with currently live nodes: 2
   [junit4]   2> 3322581 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:51270_solr]
   [junit4]   2> 3322581 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"21d86fbf495b1T6ukxg2k0wo1xddpnhzta2az7c",
   [junit4]   2>   "source":"node_lost_restore_trigger",
   [junit4]   2>   "eventTime":595415543354801,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[595415543354801],
   [junit4]   2>     "nodeNames":["127.0.0.1:51270_solr"]}}
   [junit4]   2> 3322582 DEBUG (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_lost_restore_trigger]
   [junit4]   2> 3322582 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 3322583 INFO  (ScheduledTrigger-13432-thread-1) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3322583 DEBUG 
(AutoscalingActionExecutor-13433-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"21d86fbf495b1T6ukxg2k0wo1xddpnhzta2az7c",
   [junit4]   2>   "source":"node_lost_restore_trigger",
   [junit4]   2>   "eventTime":595415543354801,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[595415543354801],
   [junit4]   2>     "_enqueue_time_":595415545096109,
   [junit4]   2>     "nodeNames":["127.0.0.1:51270_solr"]}}
   [junit4]   2> 3322584 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[9DAE0B00742EAE53])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState
   [junit4]   2> 3322590 DEBUG 
(AutoscalingActionExecutor-13433-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_lost_restore_trigger after 5000ms
   [junit4]   2> 3322591 DEBUG 
(AutoscalingActionExecutor-13433-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 7 
ms for event id=21d86fbf495b1T6ukxg2k0wo1xddpnhzta2az7c
   [junit4]   2> 3322601 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testSearchRate
   [junit4]   2> 3322602 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
   [junit4]   2> 3322602 DEBUG 
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 5
   [junit4]   2> 3322602 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 5
   [junit4]   2> 3322604 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3322604 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3322606 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 3322606 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3322607 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3322607 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3322608 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3322608 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@481ff45b{/solr,null,AVAILABLE}
   [junit4]   2> 3322608 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@5f16918a{HTTP/1.1,[http/1.1]}{127.0.0.1:51286}
   [junit4]   2> 3322608 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server Started @3326839ms
   [junit4]   2> 3322608 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51286}
   [junit4]   2> 3322608 ERROR 
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3322609 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3322609 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3322609 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3322609 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:36.594Z
   [junit4]   2> 3322611 INFO  (zkConnectionManagerCallback-8999-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322612 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3322623 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3322624 INFO  (zkConnectionManagerCallback-9003-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322628 INFO  
(zkConnectionManagerCallback-9005-thread-1-processing-n:127.0.0.1:51286_solr) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322639 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3322643 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3322646 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51286_solr
   [junit4]   2> 3322648 INFO  (zkCallback-8986-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3322648 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3322648 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3322648 INFO  
(zkCallback-9004-thread-1-processing-n:127.0.0.1:51286_solr) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3322744 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51286.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322752 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51286.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322753 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51286.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322755 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node4/.
   [junit4]   2> 3322813 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3322814 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3322814 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3322814 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3322814 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@700a835b{/solr,null,AVAILABLE}
   [junit4]   2> 3322815 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@66c1aaa8{HTTP/1.1,[http/1.1]}{127.0.0.1:51292}
   [junit4]   2> 3322815 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server Started @3327046ms
   [junit4]   2> 3322815 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51292}
   [junit4]   2> 3322815 ERROR 
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3322815 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3322815 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3322816 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3322816 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:36.801Z
   [junit4]   2> 3322818 INFO  (zkConnectionManagerCallback-9009-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322819 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3322828 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3322830 INFO  (zkConnectionManagerCallback-9013-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322833 INFO  
(zkConnectionManagerCallback-9015-thread-1-processing-n:127.0.0.1:51292_solr) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3322845 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3322848 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3322852 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51292_solr
   [junit4]   2> 3322854 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3322855 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3322855 INFO  
(zkCallback-9004-thread-1-processing-n:127.0.0.1:51286_solr) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3322855 INFO  (zkCallback-8986-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3322855 INFO  
(zkCallback-9014-thread-1-processing-n:127.0.0.1:51292_solr) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3322942 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51292.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322952 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51292.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322952 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51292.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3322953 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node5/.
   [junit4]   2> 3323006 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3323008 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3323008 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3323008 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3323008 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@b3abbeb{/solr,null,AVAILABLE}
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4e937d24{HTTP/1.1,[http/1.1]}{127.0.0.1:51296}
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.e.j.s.Server Started @3327239ms
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=51296}
   [junit4]   2> 3323009 ERROR 
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3323009 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-01-25T15:41:36.994Z
   [junit4]   2> 3323011 INFO  (zkConnectionManagerCallback-9019-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3323012 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3323021 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51253/solr
   [junit4]   2> 3323022 INFO  (zkConnectionManagerCallback-9023-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3323026 INFO  
(zkConnectionManagerCallback-9025-thread-1-processing-n:127.0.0.1:51296_solr) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3323038 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 3323042 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3323046 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:51296_solr
   [junit4]   2> 3323048 INFO  
(zkCallback-9004-thread-1-processing-n:127.0.0.1:51286_solr) 
[n:127.0.0.1:51286_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3323048 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3323048 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3323049 INFO  
(zkCallback-9024-thread-1-processing-n:127.0.0.1:51296_solr) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3323049 INFO  
(zkCallback-9014-thread-1-processing-n:127.0.0.1:51292_solr) 
[n:127.0.0.1:51292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3323048 INFO  (zkCallback-8986-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
   [junit4]   2> 3323117 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51296.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3323129 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51296.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3323129 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51296.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3323131 INFO  
(TEST-TriggerIntegrationTest.testSearchRate-seed#[9DAE0B00742EAE53]) 
[n:127.0.0.1:51296_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node6/.
   [junit4]   2> 3323214 INFO  (qtp648975697-35493) [n:127.0.0.1:51256_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&name=collection1&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 3323217 INFO  
(OverseerThreadFactory-13434-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection 
collection1
   [junit4]   2> 3323330 INFO  
(OverseerStateUpdate-99411223791009798-127.0.0.1:51257_solr-n_0000000000) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"collection1_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:51257/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 3323333 INFO  
(OverseerStateUpdate-99411223791009798-127.0.0.1:51257_solr-n_0000000000) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"collection1_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:51256/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 3323551 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=1&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 3323551 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr    
] o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n2&action=CREATE&numShards=1&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 3323552 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 3323552 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr    
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 3323670 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3323670 INFO  
(zkCallback-8976-thread-1-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3323671 INFO  
(zkCallback-8974-thread-2-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3323671 INFO  
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3324584 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
   [junit4]   2> 3324584 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
   [junit4]   2> 3324594 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.IndexSchema [collection1_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 3324596 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.s.IndexSchema [collection1_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 3324598 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3324598 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using 
configuration from collection collection1, trusted=true
   [junit4]   2> 3324599 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 3324599 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n2' using 
configuration from collection collection1, trusted=true
   [junit4]   2> 3324599 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51257.solr.core.collection1.shard1.replica_n1' (registry 
'solr.core.collection1.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3324599 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 3324599 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SolrCore [[collection1_shard1_replica_n1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node2/collection1_shard1_replica_n1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node2/./collection1_shard1_replica_n1/data/]
   [junit4]   2> 3324600 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_51256.solr.core.collection1.shard1.replica_n2' (registry 
'solr.core.collection1.shard1.replica_n2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@7e983e2f
   [junit4]   2> 3324600 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 3324600 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.SolrCore [[collection1_shard1_replica_n2] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node1/collection1_shard1_replica_n2],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_9DAE0B00742EAE53-001/tempDir-001/node1/./collection1_shard1_replica_n2/data/]
   [junit4]   2> 3324674 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 3324674 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3324675 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 3324675 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3324677 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3324677 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3324679 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3324679 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3324679 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@140193f8[collection1_shard1_replica_n2] main]
   [junit4]   2> 3324681 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3324681 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6cc0eff7[collection1_shard1_replica_n1] main]
   [junit4]   2> 3324682 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3324683 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 3324683 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1590579585265696768
   [junit4]   2> 3324684 INFO  
(searcherExecutor-13465-thread-1-processing-n:127.0.0.1:51256_solr 
x:collection1_shard1_replica_n2 s:shard1 c:collection1 r:core_node4) 
[n:127.0.0.1:51256_solr c:collection1 s:shard1 r:core_node4 
x:collection1_shard1_replica_n2] o.a.s.c.SolrCore 
[collection1_shard1_replica_n2] Registered new searcher 
Searcher@140193f8[collection1_shard1_replica_n2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3324684 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 3324684 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 3324685 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 3324685 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1590579585267793920
   [junit4]   2> 3324686 INFO  
(searcherExecutor-13464-thread-1-processing-n:127.0.0.1:51257_solr 
x:collection1_shard1_replica_n1 s:shard1 c:collection1 r:core_node3) 
[n:127.0.0.1:51257_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.c.SolrCore 
[collection1_shard1_replica_n1] Registered new searcher 
Searcher@6cc0eff7[collection1_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3324692 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 3324692 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 3324692 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:51256/solr/collection1_shard1_replica_n2/
   [junit4]   2> 3324693 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n2 
url=http://127.0.0.1:51256/solr START 
replicas=[http://127.0.0.1:51257/solr/collection1_shard1_replica_n1/] 
nUpdates=100
   [junit4]   2> 3324695 INFO  (qtp94106374-35503) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 3324796 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3324797 INFO  
(zkCallback-8976-thread-3-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3324796 INFO  
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3324796 INFO  
(zkCallback-8974-thread-2-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3324993 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n2 
url=http://127.0.0.1:51256/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 3324994 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 3324994 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we 
can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 3324994 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 3325000 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:51256/solr/collection1_shard1_replica_n2/ shard1
   [junit4]   2> 3325112 INFO  
(zkCallback-8974-thread-2-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325112 INFO  
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325112 INFO  
(zkCallback-8976-thread-3-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325112 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325168 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 3325172 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=collection1_shard1_replica_n2&action=CREATE&numShards=1&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1620
   [junit4]   2> 3325283 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325283 INFO  
(zkCallback-8974-thread-2-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325283 INFO  
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325283 INFO  
(zkCallback-8976-thread-3-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325698 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_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=collection1_shard1_replica_n1&action=CREATE&numShards=1&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2146
   [junit4]   2> 3325701 INFO  (qtp648975697-35493) [n:127.0.0.1:51256_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> 3325808 INFO  
(zkCallback-8974-thread-2-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325808 INFO  
(zkCallback-8974-thread-1-processing-n:127.0.0.1:51256_solr) 
[n:127.0.0.1:51256_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325808 INFO  
(zkCallback-8976-thread-3-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3325808 INFO  
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 3326711 INFO  (qtp648975697-35493) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&name=collection1&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2}
 status=0 QTime=3496
   [junit4]   2> 3326718 INFO  (qtp620101137-35582) [n:127.0.0.1:51286_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326720 INFO  (qtp1450649010-35606) [n:127.0.0.1:51292_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326722 INFO  (qtp1509209617-35634) [n:127.0.0.1:51296_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326723 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n1:INDEX.sizeInBytes}
 status=0 QTime=0
   [junit4]   2> 3326724 INFO  (qtp94106374-35504) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326725 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n2:INDEX.sizeInBytes}
 status=0 QTime=0
   [junit4]   2> 3326727 INFO  (qtp648975697-35495) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326728 DEBUG (qtp1509209617-35630) [n:127.0.0.1:51296_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3326728 INFO  (qtp1509209617-35630) [n:127.0.0.1:51296_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=14
   [junit4]   2> 3326730 DEBUG 
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 6
   [junit4]   2> 3326731 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 6
   [junit4]   2> 3326733 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3326734 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3326735 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 3326737 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n1:QUERY./select.requestTimes:1minRate}
 status=0 QTime=0
   [junit4]   2> 3326739 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n2:QUERY./select.requestTimes:1minRate}
 status=0 QTime=0
   [junit4]   2> 3326739 INFO  (qtp620101137-35587) [n:127.0.0.1:51286_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326740 INFO  (qtp1450649010-35610) [n:127.0.0.1:51292_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326742 INFO  (qtp1509209617-35634) [n:127.0.0.1:51296_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326743 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n1:INDEX.sizeInBytes}
 status=0 QTime=0
   [junit4]   2> 3326744 INFO  (qtp94106374-35504) [n:127.0.0.1:51257_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326745 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={wt=javabin&version=2&key=solr.core.collection1.shard1.replica_n2:INDEX.sizeInBytes}
 status=0 QTime=0
   [junit4]   2> 3326747 INFO  (qtp648975697-35495) [n:127.0.0.1:51256_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3326747 DEBUG (qtp620101137-35582) [n:127.0.0.1:51286_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3326748 INFO  (qtp620101137-35582) [n:127.0.0.1:51286_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=13
   [junit4]   2> 3326748 DEBUG 
(zkCallback-8976-thread-2-processing-n:127.0.0.1:51257_solr) 
[n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 7
   [junit4]   2> 3326749 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 7
   [junit4]   2> 3326749 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.S.Request [collection1_shard1_replica_n2]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326750 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3326751 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3326751 DEBUG 
(OverseerAutoScalingTriggerThread-99411223791009798-127.0.0.1:51257_solr-n_0000000000)
 [n:127.0.0.1:51257_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 3326752 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326752 INFO  (qtp648975697-35495) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.S.Request [collection1_shard1_replica_n2]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326753 INFO  (qtp94106374-35504) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326754 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326754 INFO  (qtp94106374-35504) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326755 INFO  (qtp94106374-35501) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326755 INFO  (qtp94106374-35504) [n:127.0.0.1:51257_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=*:*&_stateVer_=collection1:6&wt=javabin&version=2} hits=0 status=0 
QTime=0
   [junit4]   2> 3326756 INFO  (qtp648975697-35496) [n:127.0.0.1:51256_solr 
c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n2] 
o.a.s.c.S.Request [collection1_shard1_replica_n2]  webapp=/solr path=/select 
params={q=*:*&_s

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

 TestGraphTermsQParserPlugin, PrimUtilsTest, TestAuthenticationFramework, 
PrimitiveFieldTypeTest, UpdateParamsTest, TestCustomStream, 
TestIndexingPerformance, XsltUpdateRequestHandlerTest, 
TestWordDelimiterFilterFactory, TestFieldCacheSort, 
DefaultValueUpdateProcessorTest, OverseerCollectionConfigSetProcessorTest, 
TestFreeTextSuggestions, TestOverriddenPrefixQueryForCustomFieldType, 
TestSolrCoreProperties, EchoParamsTest, AutoAddReplicasPlanActionTest, 
TestExclusionRuleCollectionAccess, TestReloadDeadlock, ConfigSetsAPITest, 
DistributedSpellCheckComponentTest, TestStressLucene, RestartWhileUpdatingTest, 
TestStressLiveNodes, TestSSLRandomization, CursorMarkTest, MetricsConfigTest, 
FullSolrCloudDistribCmdsTest, TestChildDocTransformer, CollectionReloadTest, 
BasicDistributedZk2Test, TestFieldCacheVsDocValues, 
TestRetrieveFieldsOptimizer, ActionThrottleTest, 
DistributedFacetPivotSmallTest, TestCloudPivotFacet, PreAnalyzedFieldTest, 
DocumentAnalysisRequestHandlerTest, RegexBoostProcessorTest, 
ResponseLogComponentTest, TestRandomDVFaceting, MissingSegmentRecoveryTest, 
TestOrdValues, TestPHPSerializedResponseWriter, SolrJmxReporterTest, 
SystemInfoHandlerTest, TestFieldTypeResource, UUIDFieldTest, TestLegacyField, 
TestLocalFSCloudBackupRestore, TestRebalanceLeaders, TimeZoneUtilsTest, 
TestLRUCache, SpellCheckCollatorWithCollapseTest, DOMUtilTest, 
SuggestComponentContextFilterQueryTest, TestCoreAdminApis, 
NotRequiredUniqueKeyTest, TestSimpleTextCodec, HLLSerializationTest, 
DistributedQueryComponentCustomSortTest, ReplaceNodeTest, HttpPartitionTest, 
SpellCheckCollatorTest, MetricTriggerTest, QueryParsingTest, 
TestSimpleQParserPlugin, TestValueSourceCache, ReturnFieldsTest, 
DistributedSuggestComponentTest, BigEndianAscendingWordSerializerTest, 
TolerantUpdateProcessorTest, TestGeoJSONResponseWriter, 
DisMaxRequestHandlerTest, TestJettySolrRunner, TestNamedUpdateProcessors, 
TestBadConfig, DistribDocExpirationUpdateProcessorTest, RequestHandlersTest, 
TestSimDistributedQueue, SliceStateTest, TestTolerantUpdateProcessorCloud, 
CircularListTest, TestComputePlanAction, TestMultiValuedNumericRangeQuery, 
CloudMLTQParserTest, TestDFRSimilarityFactory, TestOnReconnectListenerSupport, 
InfixSuggestersTest, CSVRequestHandlerTest, TestReqParamsAPI, 
TestRawResponseWriter, TestJavabinTupleStreamParser, 
TestSubQueryTransformerCrossCore, TestAnalyzedSuggestions, 
IndexBasedSpellCheckerTest, ChaosMonkeyNothingIsSafeTest, 
SolrMetricsIntegrationTest, FileBasedSpellCheckerTest, 
TestCollapseQParserPlugin, ComputePlanActionTest, TestSort, 
TestReRankQParserPlugin, TestConfigReload, TestDocBasedVersionConstraints, 
PeerSyncTest, ChaosMonkeySafeLeaderWithPullReplicasTest, ZkStateReaderTest, 
TestInPlaceUpdatesStandalone, AsyncCallRequestStatusResponseTest, 
TestInitParams, ZkSolrClientTest, CreateCollectionCleanupTest, 
TestHashPartitioner, PreAnalyzedFieldManagedSchemaCloudTest, 
TestBlendedInfixSuggestions, TestSchemalessBufferedUpdates, 
DistributedIntervalFacetingTest, BlockCacheTest, DistributedTermsComponentTest, 
TestSolrConfigHandlerCloud, TestRandomFaceting, SyncSliceTest, 
TestCloudRecovery, ClassificationUpdateProcessorFactoryTest, 
TestManagedSchemaAPI, SecurityConfHandlerTest, TestSolrIndexConfig, 
DistanceFunctionTest, TestLuceneMatchVersion, TestFastLRUCache, 
TestImpersonationWithHadoopAuth, TestQuerySenderListener, 
SolrCloudReportersTest, TestDocSet, TestDistributedSearch, TestRestManager, 
SolrCloudExampleTest, TestSkipOverseerOperations, 
DocExpirationUpdateProcessorFactoryTest, TestJsonFacets, 
TestSchemaVersionResource, TestShortCircuitedRequests, TestHdfsUpdateLog, 
TestBackupRepositoryFactory, SortByFunctionTest, BasicFunctionalityTest, 
TestStressReorder, TestLMDirichletSimilarityFactory, DocValuesNotIndexedTest, 
TestCloudSchemaless, TestSolrXml, URLClassifyProcessorTest, 
DistributedFacetSimpleRefinementLongTailTest, DistanceUnitsTest, 
MultiThreadedOCPTest, GraphQueryTest, SmileWriterTest, TestCoreDiscovery, 
StatsReloadRaceTest, TestPKIAuthenticationPlugin, TestNestedDocsSort, 
DistributedDebugComponentTest, HighlighterConfigTest, 
FieldAnalysisRequestHandlerTest, DeleteLastCustomShardedReplicaTest, 
DebugComponentTest, TermVectorComponentTest, DeleteStatusTest, 
HdfsLockFactoryTest, TestDistribDocBasedVersion, ClusterStateTest, 
HdfsBasicDistributedZkTest, TestDynamicFieldResource, TestXmlQParser, 
CdcrUpdateLogTest, EnumFieldTest, TestFastWriter, ChaosMonkeySafeLeaderTest, 
UnloadDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, 
ShardRoutingTest, BasicZkTest, ClusterStateUpdateTest, TestZkChroot, ZkCLITest, 
ShardRoutingCustomTest, TestDistributedGrouping, ZkControllerTest, 
TestRealTimeGet, TestStressVersions, TestCoreContainer, SimpleFacetsTest, 
SpellCheckComponentTest, SolrCmdDistributorTest, BadIndexSchemaTest, 
ConvertedLegacyTest, DirectUpdateHandlerTest, HighlighterTest, 
SoftAutoCommitTest, ShowFileRequestHandlerTest, 
DistributedQueryElevationComponentTest, SimplePostToolTest, 
SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, 
CoreAdminHandlerTest, DocValuesTest, SuggesterTest, TestTrie, 
SuggesterWFSTTest, TestCSVLoader, NoCacheHeaderTest, 
WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, 
SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, TestUpdate, 
TestAtomicUpdateErrorCases, StatelessScriptUpdateProcessorFactoryTest, 
TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, 
TestSurroundQueryParser, TestQueryUtils, TestWriterPerf, 
DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, 
TestOmitPositions, TermsComponentTest, XmlUpdateRequestHandlerTest, 
MoreLikeThisHandlerTest, TestSolrQueryParser, IndexSchemaRuntimeFieldTest, 
LoggingHandlerTest, IndexSchemaTest, TestCollationField, 
UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, JsonLoaderTest, 
TestComponentsName, SearchHandlerTest, AlternateDirectoryTest, 
SolrIndexConfigTest, BadComponentTest, TestSolrDeletionPolicy2, MultiTermTest, 
SampleTest, TestBinaryField, TestSearchPerf, NumericFieldsTest, 
MinimalSchemaTest, TestConfig, TestFuzzyAnalyzedSuggestions, 
ExternalFileFieldSortTest, TestPostingsSolrHighlighter, TestPhraseSuggestions, 
SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, 
TestSweetSpotSimilarityFactory, TestLMJelinekMercerSimilarityFactory, 
TestIBSimilarityFactory, ResourceLoaderTest, ScriptEngineTest, 
OpenExchangeRatesOrgProviderTest, TestSystemIdResolver, 
TestSuggestSpellingConverter, DateFieldTest, TestSolrJ, TestDocumentBuilder, 
ZkNodePropsTest, DistributedMLTComponentTest, SolrTestCaseJ4Test, 
TestCrossCoreJoin, TestDistributedMissingSort, TestSimpleTrackingShardHandler, 
TestTolerantSearch, TestLuceneIndexBackCompat, 
TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, 
AddReplicaTest, AliasIntegrationTest, AssignBackwardCompatibilityTest, 
ChaosMonkeyNothingIsSafeWithPullReplicasTest, CleanupOldIndexTest, 
CloudExitableDirectoryReaderTest, CollectionStateFormat2Test, 
ConnectionManagerTest, DeleteReplicaTest, DeleteShardTest, 
DistributedQueueTest, ForceLeaderTest, LeaderInitiatedRecoveryOnCommitTest, 
MoveReplicaHDFSTest, MoveReplicaTest, OutOfBoxZkACLAndCredentialsProvidersTest, 
OverseerRolesTest, RollingRestartTest, TestCloudPseudoReturnFields, 
TestClusterProperties, TestConfigSetsAPI, TestLeaderInitiatedRecoveryThread, 
TestPullReplicaErrorHandling, TestRandomFlRTGCloud, TestRequestForwarding, 
TestSegmentSorting, TestSolrCloudWithDelegationTokens, 
TestSolrCloudWithKerberosAlt, TestSolrCloudWithSecureImpersonation, 
TestTlogReplica, CollectionsAPIAsyncDistributedZkTest, 
CollectionsAPIDistributedZkTest, SimpleCollectionCreateDeleteTest, 
TestCollectionsAPIViaSolrCloudCluster, TestHdfsCloudBackupRestore, 
TestRequestStatusCollectionAPI, AutoScalingHandlerTest, ExecutePlanActionTest, 
HdfsAutoAddReplicasIntegrationTest, NodeAddedTriggerTest, NodeLostTriggerTest, 
SearchRateTriggerTest, SystemLogListenerTest, TestPolicyCloud, 
TriggerIntegrationTest]
   [junit4] Completed [611/767 (1!)] on J1 in 192.98s, 14 tests, 1 failure <<< 
FAILURES!

[...truncated 37065 lines...]
-ecj-javadoc-lint-tests:
    [mkdir] Created dir: 
/var/folders/qg/h2dfw5s161s51l2bn79mrb7r0000gn/T/ecj1687022588
 [ecj-lint] Compiling 19 source files to 
/var/folders/qg/h2dfw5s161s51l2bn79mrb7r0000gn/T/ecj1687022588
 [ecj-lint] ----------
 [ecj-lint] 1. ERROR in 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/spatial3d/src/test/org/apache/lucene/spatial3d/geom/RandomPlaneTest.java
 (at line 20)
 [ecj-lint]     import java.util.ArrayList;
 [ecj-lint]            ^^^^^^^^^^^^^^^^^^^
 [ecj-lint] The import java.util.ArrayList is never used
 [ecj-lint] ----------
 [ecj-lint] 2. ERROR in 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/spatial3d/src/test/org/apache/lucene/spatial3d/geom/RandomPlaneTest.java
 (at line 21)
 [ecj-lint]     import java.util.List;
 [ecj-lint]            ^^^^^^^^^^^^^^
 [ecj-lint] The import java.util.List is never used
 [ecj-lint] ----------
 [ecj-lint] 2 problems (2 errors)

BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:836: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:101: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build.xml:208: The 
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:2281: 
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:2112: 
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:2145: 
Compile failed; see the compiler error output for details.

Total time: 96 minutes 57 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to