You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/06/16 08:52:34 UTC
[JENKINS] Lucene-Solr-NightlyTests-7.4 - Build # 6 - Still Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-7.4/6/
3 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration
Error Message:
last state: DocCollection(testSplitIntegration_collection//clusterstate.json/41)={ "replicationFactor":"2", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"2", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0", "autoCreated":"true", "shards":{ "shard2":{ "replicas":{ "core_node3":{ "core":"testSplitIntegration_collection_shard2_replica_n3", "leader":"true", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"active"}}}
Stack Trace:
java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/41)={
"replicationFactor":"2",
"pullReplicas":"0",
"router":{"name":"compositeId"},
"maxShardsPerNode":"2",
"autoAddReplicas":"false",
"nrtReplicas":"2",
"tlogReplicas":"0",
"autoCreated":"true",
"shards":{
"shard2":{
"replicas":{
"core_node3":{
"core":"testSplitIntegration_collection_shard2_replica_n3",
"leader":"true",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11},
"core_node4":{
"core":"testSplitIntegration_collection_shard2_replica_n4",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11}},
"range":"0-7fffffff",
"state":"active"},
"shard1":{
"replicas":{
"core_node1":{
"core":"testSplitIntegration_collection_shard1_replica_n1",
"leader":"true",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14},
"core_node2":{
"core":"testSplitIntegration_collection_shard1_replica_n2",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14}},
"range":"80000000-ffffffff",
"state":"active"}}}
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:5D95688B9EDC0B4D]:0)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111)
at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:300)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.autoscaling.SystemLogListenerTest.test
Error Message:
Trigger was not fired
Stack Trace:
java.lang.AssertionError: Trigger was not fired
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:EC4FEE111FDFAF4B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.SystemLogListenerTest.test(SystemLogListenerTest.java:151)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testTriggerThrottling
Error Message:
Both triggers should have fired by now
Stack Trace:
java.lang.AssertionError: Both triggers should have fired by now
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:9F3979EE63892121]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testTriggerThrottling(TestTriggerIntegration.java:185)
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 13385 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
[junit4] 2> 123656 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_641BD1CBB123C2B3-001/init-core-data-001
[junit4] 2> 123658 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 123660 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 125925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 125927 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 125947 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 125976 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 126024 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 126024 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 126045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] IGNOR/A 0.07s J0 | TestTriggerIntegration.testNodeLostTriggerRestoreState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 126080 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126080 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 126081 DEBUG (ScheduledTrigger-66-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126266 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126359 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126379 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126392 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 126393 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 126394 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 126394 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 126412 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 126431 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 126431 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 126433 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 126469 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126489 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126490 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 126490 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126652 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126655 DEBUG (simCloudManagerPool-70-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126655 DEBUG (simCloudManagerPool-70-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 126710 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 126713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 126746 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126764 DEBUG (simCloudManagerPool-70-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126765 DEBUG (simCloudManagerPool-70-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 126782 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 126784 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 126785 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126785 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126785 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 126912 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126921 DEBUG (simCloudManagerPool-70-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126921 DEBUG (simCloudManagerPool-70-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 126922 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126922 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 126931 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 126931 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 126931 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10002_solr at time 11462030256135597
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10002_solr] added at times [11462030256135597], now=11462030259808797
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":11462030256135597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462030256135597],
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 126966 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 127348 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 127350 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 3
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testTriggerThrottling -Dtests.seed=641BD1CBB123C2B3 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/test-data/enwiki.random.lines.txt -Dtests.locale=sl -Dtests.timezone=Canada/Newfoundland -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 1.39s J0 | TestTriggerIntegration.testTriggerThrottling <<<
[junit4] > Throwable #1: java.lang.AssertionError: Both triggers should have fired by now
[junit4] > at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:9F3979EE63892121]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testTriggerThrottling(TestTriggerIntegration.java:185)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testCooldown
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testEventFromRestoredState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.02s J0 | TestTriggerIntegration.testNodeMarkersRegistration
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 127605 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 127605 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 127606 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10002_solr
[junit4] 2> 127606 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 127608 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 127657 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10002_solr
[junit4] 2> 127657 DEBUG (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":11462030256135597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462030256135597],
[junit4] 2> "_enqueue_time_":11462031064994597,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 127658 INFO (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger1
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 127658 WARN (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> java.lang.NullPointerException: null
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:320) ~[java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 127821 DEBUG (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 8214 ms for event id=28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 127856 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 127892 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 127912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 127912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 127913 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 127978 DEBUG (simCloudManagerPool-73-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 127978 DEBUG (simCloudManagerPool-73-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 128039 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128060 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128095 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128097 DEBUG (simCloudManagerPool-73-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 128098 DEBUG (simCloudManagerPool-73-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 128111 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 128112 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 11462088427305797
[junit4] 2> 128132 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 128133 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128133 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128152 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [11462088427305797], now=11462090481367097
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":11462088427305797,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462088427305797],
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 128168 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 128234 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10003_solr
[junit4] 2> 128255 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":11462088427305797,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462088427305797],
[junit4] 2> "_enqueue_time_":11462091199083347,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 128290 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 128291 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 128291 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1768 ms for event id=28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v
[junit4] 2> 128348 DEBUG (simCloudManagerPool-73-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 128348 DEBUG (simCloudManagerPool-73-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 128363 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 128364 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 128400 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 128403 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 2
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [.system]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 1
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2>
[junit4] 2> 128403 DEBUG (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testSearchRate
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testListeners
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testNodeAddedTriggerRestoreState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testEventQueue
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testNodeLostTrigger
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 128423 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 128423 WARN (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger ran but was already closed
[junit4] 2> 128424 ERROR (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Unexpected exception in NodeAddedTrigger
[junit4] 2> java.lang.RuntimeException: Trigger has been closed
[junit4] 2> at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:121) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:589) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 128436 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_641BD1CBB123C2B3-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1251, maxMBSortInHeap=7.53348972723326, sim=RandomSimilarity(queryNorm=true): {}, locale=sl, timezone=Canada/Newfoundland
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=217110632,total=279445504
[junit4] 2> NOTE: All tests run in this JVM: [TestCollationField, RestoreTriggerStateTest, TestTriggerIntegration]
[junit4] Completed [7/817 (1!)] on J0 in 5.52s, 11 tests, 1 failure, 9 skipped <<< FAILURES!
[...truncated 37 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.SystemLogListenerTest
[junit4] 2> 128731 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/init-core-data-001
[junit4] 2> 128751 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 128753 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 128786 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001
[junit4] 2> 128787 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 128807 INFO (Thread-44) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 128807 INFO (Thread-44) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 128823 ERROR (Thread-44) [ ] 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> 128912 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35652
[junit4] 2> 129099 INFO (zkConnectionManagerCallback-81-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 129490 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129491 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129494 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129657 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ae364ae{/solr,null,AVAILABLE}
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5a959c13{HTTP/1.1,[http/1.1]}{127.0.0.1:40138}
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.Server Started @129897ms
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40138}
[junit4] 2> 129683 ERROR (jetty-launcher-78-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.054Z
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129794 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@24f564e8{/solr,null,AVAILABLE}
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5b81883a{HTTP/1.1,[http/1.1]}{127.0.0.1:35754}
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.Server Started @130010ms
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35754}
[junit4] 2> 129796 ERROR (jetty-launcher-78-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.167Z
[junit4] 2> 129851 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129851 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129852 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129880 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@48fc3aea{/solr,null,AVAILABLE}
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7ba465c5{HTTP/1.1,[http/1.1]}{127.0.0.1:45600}
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.Server Started @130096ms
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45600}
[junit4] 2> 129881 ERROR (jetty-launcher-78-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.253Z
[junit4] 2> 130071 INFO (zkConnectionManagerCallback-87-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130071 INFO (zkConnectionManagerCallback-85-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130095 INFO (zkConnectionManagerCallback-83-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130108 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 130108 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 130109 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 132416 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 132629 INFO (zkConnectionManagerCallback-91-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 132764 INFO (zkConnectionManagerCallback-93-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133123 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 133313 INFO (zkConnectionManagerCallback-99-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133577 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 133737 INFO (zkConnectionManagerCallback-105-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133833 INFO (zkConnectionManagerCallback-101-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 134037 INFO (zkConnectionManagerCallback-107-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 134586 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 134587 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45600_solr
[junit4] 2> 134606 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.Overseer Overseer (id=72808765580443656-127.0.0.1:45600_solr-n_0000000000) starting
[junit4] 2> 134660 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 134680 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35754_solr
[junit4] 2> 134861 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135056 INFO (zkCallback-100-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135401 INFO (zkConnectionManagerCallback-116-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 135649 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135674 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 135690 INFO (zkConnectionManagerCallback-121-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 135712 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 135712 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135728 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 135728 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45600_solr
[junit4] 2> 135729 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 135763 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 135764 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 135765 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 135765 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 135766 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 135893 INFO (zkCallback-115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 135910 INFO (zkCallback-100-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 136021 INFO (zkCallback-120-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 136138 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 136573 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136686 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136689 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:35754_solr, 127.0.0.1:45600_solr]
[junit4] 2> 136844 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 136864 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 136865 DEBUG (ScheduledTrigger-93-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 136877 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136877 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136879 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/.
[junit4] 2> 136914 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136914 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136935 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node3/.
[junit4] 2> 137952 DEBUG (ScheduledTrigger-93-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 138357 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 138428 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 138560 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 138560 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40138_solr
[junit4] 2> 138723 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138743 INFO (zkCallback-120-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138743 INFO (zkCallback-100-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138760 INFO (zkCallback-115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138856 INFO (zkCallback-92-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138952 DEBUG (ScheduledTrigger-93-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 139004 INFO (zkConnectionManagerCallback-128-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 139080 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 139264 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 139280 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 139479 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139647 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139647 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139649 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/.
[junit4] 2> 140086 DEBUG (ScheduledTrigger-93-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 140500 INFO (zkConnectionManagerCallback-131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 140624 INFO (zkConnectionManagerCallback-136-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 140626 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 140640 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 140701 INFO (qtp103186778-272) [n:127.0.0.1:45600_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=3&name=.system&nrtReplicas=3&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 141094 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 141172 INFO (OverseerThreadFactory-95-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 141666 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40138/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 141682 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35754/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 141719 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45600/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 142095 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 142098 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr x:.system_shard1_replica_n3] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n3&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 142225 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr x:.system_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 142226 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr x:.system_shard1_replica_n2] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 142243 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr x:.system_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 143111 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 143581 WARN (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.Config You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
[junit4] 2> 143632 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 143634 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 143654 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 144011 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144011 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144026 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144086 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.IndexSchema [.system_shard1_replica_n3] Schema name=_system collection or core
[junit4] 2> 144100 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 144119 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 144121 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 144382 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144413 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144425 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144500 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 144534 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 144537 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 144537 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from collection .system, trusted=true
[junit4] 2> 144538 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 144575 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, the non-managed schema /configs/.system/schema.xml no longer exists.
[junit4] 2> 144575 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n3' using configuration from collection .system, trusted=true
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.core..system.shard1.replica_n3' (registry 'solr.core..system.shard1.replica_n3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrCore [[.system_shard1_replica_n3] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/.system_shard1_replica_n3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/./.system_shard1_replica_n3/data/]
[junit4] 2> 144612 WARN (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchemaFactory Error persisting managed schema resource managed-schema
[junit4] 2> org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /configs/.system/schema.xml
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:114) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:876) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$delete$1(SolrZkClient.java:245) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:244) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.zkUgradeToManagedSchema(ManagedIndexSchemaFactory.java:349) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.upgradeToManagedSchema(ManagedIndexSchemaFactory.java:268) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:186) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:45) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.IndexSchemaFactory.buildIndexSchema(IndexSchemaFactory.java:75) ~[java/:?]
[junit4] 2> at org.apache.solr.core.ConfigSetService.createIndexSchema(ConfigSetService.java:119) ~[java/:?]
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:92) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.getConfigSet(CoreContainer.java:1184) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1131) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1045) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:94) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:380) [java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:395) [java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:180) [java/:?]
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:734) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:715) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:496) [java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:377) [java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:323) [java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139) [java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:674) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:531) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:760) [jetty-util-9.4.10.v20180503.j
[...truncated too long message...]
ability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
[copy] Copying 39 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
resolve-example:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
resolve-server:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
[copy] Copying 247 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 65ms :: artifacts dl 5ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 8 | 0 | 0 | 0 || 8 | 0 |
---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...
-jenkins-base:
BUILD SUCCESSFUL
Total time: 759 minutes 10 seconds
Archiving artifacts
WARN: No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
WARN: java.lang.InterruptedException: no matches found within 10000
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)