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/08/28 05:23:43 UTC
[JENKINS] Lucene-Solr-Tests-master - Build # 2750 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2750/
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction.testNodeAdded
Error Message:
ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2cc494ca, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@539c12f] expected:<1> but was:<2>
Stack Trace:
java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2cc494ca, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@539c12f] expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([C50CB4C740164FEE:A0CFE2B0E2B5E7ED]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction.testNodeAdded(TestSimComputePlanAction.java:314)
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 12904 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
[junit4] 2> 567631 INFO (SUITE-TestSimComputePlanAction-seed#[C50CB4C740164FEE]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestSimComputePlanAction_C50CB4C740164FEE-001/init-core-data-001
[junit4] 2> 567634 INFO (SUITE-TestSimComputePlanAction-seed#[C50CB4C740164FEE]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 567635 INFO (SUITE-TestSimComputePlanAction-seed#[C50CB4C740164FEE]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 567647 DEBUG (SUITE-TestSimComputePlanAction-seed#[C50CB4C740164FEE]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10002_solr
[junit4] 2> 567648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 567648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 567649 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 567649 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 567649 INFO (SUITE-TestSimComputePlanAction-seed#[C50CB4C740164FEE]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 567650 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 567651 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 567651 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 567655 DEBUG (ScheduledTrigger-1445-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567659 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 567659 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 567659 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 567659 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 567660 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 567660 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 567660 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 567660 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 567666 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 567666 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 567676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 567676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 567677 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 567677 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 567681 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 567681 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 567681 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 567682 DEBUG (ScheduledTrigger-1450-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567702 DEBUG (ScheduledTrigger-1450-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567723 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567743 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567763 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567783 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567803 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567809 DEBUG (simCloudManagerPool-1449-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 567822 DEBUG (simCloudManagerPool-1449-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 567823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 567823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 567823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 567824 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567825 DEBUG (simCloudManagerPool-1449-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 567825 DEBUG (simCloudManagerPool-1449-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 567825 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 567825 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 567825 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 567844 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567864 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567884 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567905 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567925 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 567928 DEBUG (simCloudManagerPool-1449-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 567930 DEBUG (simCloudManagerPool-1449-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 567930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 567930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10002_solr, 127.0.0.1:10003_solr]
[junit4] 2> 567930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 567931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 567931 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 567931 DEBUG (simCloudManagerPool-1449-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
[junit4] 2> 567945 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 567949 DEBUG (simCloudManagerPool-1449-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 567951 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 567952 DEBUG (simCloudManagerPool-1449-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 567963 INFO (simCloudManagerPool-1449-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739065774 sessionWrapper.createTime 2739065229958818, this.sessionWrapper.createTime 2739065229958818
[junit4] 2> 567963 DEBUG (simCloudManagerPool-1449-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 567965 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 567971 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 567974 DEBUG (simCloudManagerPool-1449-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeLost / shard1
[junit4] 2> 567981 DEBUG (simCloudManagerPool-1449-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeLost / shard1
[junit4] 2> 567981 DEBUG (simCloudManagerPool-1449-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: core_node1
[junit4] 2> 567985 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 567992 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 567992 DEBUG (simCloudManagerPool-1449-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeLost / shard1
[junit4] 2> 567992 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -- cluster state: znodeVersion: 7
[junit4] 2> live nodes:[127.0.0.1:10003_solr, 127.0.0.1:10002_solr]
[junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/6)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 567993 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeLost / shard1
[junit4] 2> 567993 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Stopped_node : 127.0.0.1:10003_solr
[junit4] 2> 567993 DEBUG (simCloudManagerPool-1449-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeLost / shard1
[junit4] 2> 567994 INFO (simCloudManagerPool-1449-thread-8) [ ] o.a.s.c.ActionThrottle Throttling leader attempts - waiting for 4389ms
[junit4] 2> 568006 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568006 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10003_solr
[junit4] 2> 568012 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568012 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10003_solr
[junit4] 2> 568026 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568032 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568046 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568053 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568067 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568073 DEBUG (ScheduledTrigger-1450-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568082 DEBUG (simCloudManagerPool-1449-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: core_node2
[junit4] 2> 568087 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568093 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568107 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568114 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568128 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568134 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568148 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 568155 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 568155 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10003_solr]
[junit4] 2> 568155 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"9bb2b0316e956Tc5vtho0sswv7ca04lzepewa64",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739068200216918,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739068200216918],
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 568155 DEBUG (ScheduledTrigger-1450-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 568156 DEBUG (simCloudManagerPool-1449-thread-9) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 568188 DEBUG (simCloudManagerPool-1449-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 568190 DEBUG (simCloudManagerPool-1449-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 568191 INFO (simCloudManagerPool-1449-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739077145 sessionWrapper.createTime 2739077103058568, this.sessionWrapper.createTime 2739077103058568
[junit4] 2> 568191 DEBUG (simCloudManagerPool-1449-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 568209 DEBUG (simCloudManagerPool-1449-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for .system / shard1
[junit4] 2> 568216 DEBUG (simCloudManagerPool-1449-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for .system / shard1
[junit4] 2> 568216 DEBUG (simCloudManagerPool-1449-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1: core_node1
[junit4] 2> 568218 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"9bb2b0316e956Tc5vtho0sswv7ca04lzepewa64",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739068200216918,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739068200216918],
[junit4] 2> "_enqueue_time_":2739075370855318,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 568218 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"9bb2b0316e956Tc5vtho0sswv7ca04lzepewa64",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739068200216918,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739068200216918],
[junit4] 2> "_enqueue_time_":2739075370855318,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 568219 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 568220 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 568221 INFO (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10004_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 568222 INFO (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739078690 sessionWrapper.createTime 2739078583856468, this.sessionWrapper.createTime 2739078583856468
[junit4] 2> 568222 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 568224 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for .system / shard1
[junit4] 2> 568224 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 568224 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10004_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1023,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10004_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10004,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10002_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10002_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10002,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10003_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1023,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10003_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10003,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 568225 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10002_solr]
[junit4] 2> 568225 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/14)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{"core_node1":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 568225 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/14)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 568225 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLost
[junit4] 2> 568226 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 1
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 2
[junit4] 2> ## 127.0.0.1:10003_solr
[junit4] 2> ## 127.0.0.1:10004_solr
[junit4] 2> ## Collections: [.system, testNodeLost]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 1
[junit4] 2> ## Total replicas: 1
[junit4] 2> ## * testNodeLost 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 3
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - STARTED 1
[junit4] 2>
[junit4] 2> 568236 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 568237 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 568237 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 568237 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 568237 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deleted /autoscaling/nodeLost/127.0.0.1:10004_solr
[junit4] 2> 568237 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 568237 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 568237 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10004_solr
[junit4] 2> 568237 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10003_solr
[junit4] 2> 568237 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 568237 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:189) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 568238 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 568238 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 568238 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 568238 DEBUG (simCloudManagerPool-1449-thread-13) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 568239 DEBUG (simCloudManagerPool-1449-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for .system / shard1
[junit4] 2> 568238 WARN (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system
[junit4] 2> java.io.IOException: java.lang.InterruptedException
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:632) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.SystemLogListener.onEvent(SystemLogListener.java:118) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:792) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:768) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:315) ~[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> Caused by: java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:630) ~[test/:?]
[junit4] 2> ... 10 more
[junit4] 2> 568251 DEBUG (simCloudManagerPool-1449-thread-15) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 568262 DEBUG (simCloudManagerPool-1449-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for .system / shard1
[junit4] 2> 568269 DEBUG (simCloudManagerPool-1449-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for .system / shard1
[junit4] 2> 568270 DEBUG (simCloudManagerPool-1449-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1: core_node2
[junit4] 2> 569471 WARN (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Unhandled exception executing actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_lost_trigger has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:548) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:318) ~[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> 569471 DEBUG (AutoscalingActionExecutor-1451-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 62661 ms for event id=9bb2b0316e956Tc5vtho0sswv7ca04lzepewa64
[junit4] 2> 569471 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 569472 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 569472 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 569486 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 569487 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 569487 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1
[junit4] 2> 569487 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 569494 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 569502 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569503 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 569504 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569524 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569545 DEBUG (ScheduledTrigger-1453-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569565 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569584 DEBUG (simCloudManagerPool-1452-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 569584 DEBUG (simCloudManagerPool-1452-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 569585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 569585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 569587 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569604 DEBUG (simCloudManagerPool-1452-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 569604 DEBUG (simCloudManagerPool-1452-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 569604 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 569604 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569605 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 569608 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569628 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569648 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569668 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569689 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569709 DEBUG (ScheduledTrigger-1453-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569712 DEBUG (simCloudManagerPool-1452-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 569712 DEBUG (simCloudManagerPool-1452-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 569713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 569713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10002_solr, 127.0.0.1:10007_solr]
[junit4] 2> 569713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 569713 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 569714 DEBUG (simCloudManagerPool-1452-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
[junit4] 2> 569725 DEBUG (simCloudManagerPool-1452-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 569727 DEBUG (simCloudManagerPool-1452-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 569729 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569734 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 569738 INFO (simCloudManagerPool-1452-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739154489 sessionWrapper.createTime 2739153940659818, this.sessionWrapper.createTime 2739153940659818
[junit4] 2> 569738 DEBUG (simCloudManagerPool-1452-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 569749 DEBUG (ScheduledTrigger-1453-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569755 DEBUG (ScheduledTrigger-1453-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 569755 DEBUG (simCloudManagerPool-1452-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no replicas in testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569755 DEBUG (simCloudManagerPool-1452-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569756 DEBUG (simCloudManagerPool-1452-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569757 DEBUG (simCloudManagerPool-1452-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: core_node1
[junit4] 2> 569767 DEBUG (simCloudManagerPool-1452-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no replicas in testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569767 DEBUG (simCloudManagerPool-1452-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569770 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569775 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 569778 DEBUG (simCloudManagerPool-1452-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no replicas in testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569778 DEBUG (simCloudManagerPool-1452-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569789 DEBUG (simCloudManagerPool-1452-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569790 DEBUG (simCloudManagerPool-1452-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569790 DEBUG (simCloudManagerPool-1452-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569790 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569790 DEBUG (simCloudManagerPool-1452-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: core_node4
[junit4] 2> 569795 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 569800 DEBUG (simCloudManagerPool-1452-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569800 DEBUG (simCloudManagerPool-1452-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569810 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 569811 DEBUG (simCloudManagerPool-1452-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569811 DEBUG (simCloudManagerPool-1452-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569812 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -- cluster state: znodeVersion: 33
[junit4] 2> live nodes:[127.0.0.1:10002_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10007_solr]
[junit4] 2> collections:{.system=DocCollection(.system//clusterstate.json/32)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}, testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/32)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 569815 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569815 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 569815 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10006_solr
[junit4] 2> 569822 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeWithMultipleReplicasLost / shard1
[junit4] 2> 569825 DEBUG (simCloudManagerPool-1452-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeWithMultipleReplicasLost / shard2
[junit4] 2> 569826 INFO (simCloudManagerPool-1452-thread-13) [ ] o.a.s.c.ActionThrottle Throttling leader attempts - waiting for 3197ms
[junit4] 2> 569830 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 569830 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10006_solr
[junit4] 2> 569835 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 569836 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10006_solr]
[junit4] 2> 569836 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"9bb40017daef8Tc5vtho0sswv7ca04lzepewa69",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739158367710968,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739158367710968],
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 569836 DEBUG (ScheduledTrigger-1453-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 569878 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"9bb40017daef8Tc5vtho0sswv7ca04lzepewa69",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739158367710968,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739158367710968],
[junit4] 2> "_enqueue_time_":2739159416100868,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 569879 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"9bb40017daef8Tc5vtho0sswv7ca04lzepewa69",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":2739158367710968,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2739158367710968],
[junit4] 2> "_enqueue_time_":2739159416100868,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 569879 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 569880 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 569890 DEBUG (simCloudManagerPool-1452-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: core_node6
[junit4] 2> 569899 INFO (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10002_solr&inPlaceMove=true&replica=core_node4
[junit4] 2> 569908 INFO (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10002_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 569908 INFO (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739163013 sessionWrapper.createTime 2739161608536618, this.sessionWrapper.createTime 2739161608536618
[junit4] 2> 569908 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 569911 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10002_solr&inPlaceMove=true&replica=core_node4
[junit4] 2> 569911 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10002_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 569912 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 569912 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10006_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10006_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10006,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10005_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10005_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10005,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10002_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10002_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10002,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10007_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10007_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10007,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 569923 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10005_solr, 127.0.0.1:10002_solr, 127.0.0.1:10007_solr]
[junit4] 2> 569924 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/39)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":6,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":13240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.2330710887908936E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":6}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 569924 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeWithMultipleReplicasLost state: DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/39)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 569924 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeWithMultipleReplicasLost
[junit4] 2> 569925 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 1
[junit4] 2> ## 127.0.0.1:10006_solr
[junit4] 2> ## Collections: [.system, testNodeWithMultipleReplicasLost]
[junit4] 2> ## Max replicas per node: 2
[junit4] 2> ## Min replicas per node: 1
[junit4] 2> ## Total replicas: 5
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testNodeWithMultipleReplicasLost 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 4
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - AFTER_ACTION 2
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - FAILED 1
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2>
[junit4] 2> 569919 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 569926 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 569926 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 569926 DEBUG (AutoscalingActionExecutor-1454-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 2372 ms for event id=9bb40017daef8Tc5vtho0sswv7ca04lzepewa69
[junit4] 2> 569930 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 569930 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 569930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 569930 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10006_solr
[junit4] 2> 569930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 569930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569930 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10005_solr
[junit4] 2> 569930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10007_solr
[junit4] 2> 569931 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 569931 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 569931 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[C50CB4C740164FEE]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 569947 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 569947 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 569947 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion -1
[junit4] 2> 569947 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 569958 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 569974 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 569974 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 569974 DEBUG (ScheduledTrigger-1456-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 569996 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570016 DEBUG (ScheduledTrigger-1456-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570037 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570044 DEBUG (simCloudManagerPool-1455-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 570045 DEBUG (simCloudManagerPool-1455-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 570046 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 570046 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 570047 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 570047 DEBUG (simCloudManagerPool-1455-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 570048 DEBUG (simCloudManagerPool-1455-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 570048 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 570048 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 570048 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 570048 DEBUG (simCloudManagerPool-1455-thread-3) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 570057 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570063 DEBUG (simCloudManagerPool-1455-thread-3) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 570063 DEBUG (simCloudManagerPool-1455-thread-3) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 570064 INFO (simCloudManagerPool-1455-thread-3) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739170798 sessionWrapper.createTime 2739170766397918, this.sessionWrapper.createTime 2739170766397918
[junit4] 2> 570064 DEBUG (simCloudManagerPool-1455-thread-3) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 570077 DEBUG (simCloudManagerPool-1455-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for .system / shard1
[junit4] 2> 570077 DEBUG (simCloudManagerPool-1455-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for .system / shard1
[junit4] 2> 570077 DEBUG (simCloudManagerPool-1455-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1: core_node4
[junit4] 2> 570077 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570098 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570118 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570138 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570155 DEBUG (simCloudManagerPool-1455-thread-9) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 570155 DEBUG (simCloudManagerPool-1455-thread-9) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 570155 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 570156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 570156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 570156 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 570157 DEBUG (ScheduledTrigger-1456-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 570157 DEBUG (ScheduledTrigger-1456-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 570162 DEBUG (ScheduledTrigger-1456-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570163 DEBUG (simCloudManagerPool-1455-thread-10) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 570163 DEBUG (simCloudManagerPool-1455-thread-10) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 570164 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 570164 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 570166 DEBUG (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 570178 DEBUG (ScheduledTrigger-1456-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 570178 DEBUG (ScheduledTrigger-1456-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 570179 WARN (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 4 on collection testNodeAdded is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 570179 DEBUG (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 570179 DEBUG (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 570182 INFO (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 2739176689 sessionWrapper.createTime 2739176579558718, this.sessionWrapper.createTime 2739176579558718
[junit4] 2> 570182 DEBUG (simCloudManagerPool-1455-thread-11) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 570182 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570193 DEBUG (simCloudManagerPool-1455-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- submit leader election for testNodeAdded / shard1
[junit4] 2> 570193 DEBUG (simCloudManagerPool-1455-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election for testNodeAdded / shard1
[junit4] 2> 570194 DEBUG (simCloudManagerPool-1455-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeAdded / shard1: core_node1
[junit4] 2> 570199 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 570199 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 570202 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 570205 DEBUG (simCloudManagerPool-1455-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider -- already has leader testNodeAdded / shard1
[junit4] 2> 570219 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 570219 DEBUG (ScheduledTrigger-1456-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[jun
[...truncated too long message...]
ed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null507456209
[copy] Copying 238 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null507456209
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null507456209
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 60ms :: artifacts dl 8ms
---------------------------------------------------------------------
| | 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: 95 minutes 22 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$34.hasMatch(FilePath.java:2678)
at hudson.FilePath$34.invoke(FilePath.java:2557)
at hudson.FilePath$34.invoke(FilePath.java:2547)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1036)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1038)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
[JENKINS] Lucene-Solr-Tests-master - Build # 2751 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2751/
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.ScheduledTriggerTest.testTrigger
Error Message:
expected:<3> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<3> but was:<2>
at __randomizedtesting.SeedInfo.seed([5C4CFF49386EFD09:3F87C9CBA1A18E24]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.autoscaling.ScheduledTriggerTest.scheduledTriggerTest(ScheduledTriggerTest.java:113)
at org.apache.solr.cloud.autoscaling.ScheduledTriggerTest.testTrigger(ScheduledTriggerTest.java:66)
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 14038 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ScheduledTriggerTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledTriggerTest_5C4CFF49386EFD09-001/init-core-data-001
[junit4] 2> 1939098 WARN (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=32 numCloses=32
[junit4] 2> 1939098 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1939100 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-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> 1939100 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1939100 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledTriggerTest_5C4CFF49386EFD09-001/tempDir-001
[junit4] 2> 1939101 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1939101 INFO (Thread-2689) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1939101 INFO (Thread-2689) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1939103 ERROR (Thread-2689) [ ] 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> 1939201 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:46776
[junit4] 2> 1939203 INFO (zkConnectionManagerCallback-8985-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939208 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 1939209 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1939209 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1939209 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 1939209 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@204b5dd6{/solr,null,AVAILABLE}
[junit4] 2> 1939210 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@342ea6ab{SSL,[ssl, http/1.1]}{127.0.0.1:34904}
[junit4] 2> 1939210 INFO (jetty-launcher-8982-thread-1) [ ] o.e.j.s.Server Started @1938711ms
[junit4] 2> 1939210 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34904}
[junit4] 2> 1939210 ERROR (jetty-launcher-8982-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1939210 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 1939211 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 1939211 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1939211 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1939211 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-08-28T11:26:46.483Z
[junit4] 2> 1939212 INFO (zkConnectionManagerCallback-8987-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939212 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1939281 INFO (jetty-launcher-8982-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46776/solr
[junit4] 2> 1939282 INFO (zkConnectionManagerCallback-8991-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939284 INFO (zkConnectionManagerCallback-8993-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939348 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34904_solr
[junit4] 2> 1939348 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.c.Overseer Overseer (id=72237448824225795-127.0.0.1:34904_solr-n_0000000000) starting
[junit4] 2> 1939354 INFO (zkConnectionManagerCallback-9000-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939355 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46776/solr ready
[junit4] 2> 1939356 INFO (OverseerStateUpdate-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [n:127.0.0.1:34904_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:34904_solr
[junit4] 2> 1939356 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1939356 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34904_solr
[junit4] 2> 1939356 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1939357 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1939357 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1939357 INFO (OverseerStateUpdate-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [n:127.0.0.1:34904_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1939357 INFO (zkCallback-8999-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1939360 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:34904_solr]
[junit4] 2> 1939360 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1939360 DEBUG (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1939361 DEBUG (ScheduledTrigger-6168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1939377 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1939400 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34904.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49a634c5
[junit4] 2> 1939407 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34904.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49a634c5
[junit4] 2> 1939407 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34904.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@49a634c5
[junit4] 2> 1939408 INFO (jetty-launcher-8982-thread-1) [n:127.0.0.1:34904_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledTriggerTest_5C4CFF49386EFD09-001/tempDir-001/node1/.
[junit4] 2> 1939423 INFO (zkConnectionManagerCallback-9003-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939426 INFO (zkConnectionManagerCallback-9008-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1939427 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1939428 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46776/solr ready
[junit4] 2> 1939442 INFO (TEST-ScheduledTriggerTest.testIgnoredEvent-seed#[5C4CFF49386EFD09]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testIgnoredEvent
[junit4] 2> 1939444 WARN (TEST-ScheduledTriggerTest.testIgnoredEvent-seed#[5C4CFF49386EFD09]) [ ] o.a.s.c.a.ScheduledTrigger ScheduledTrigger was not able to run event at scheduled time: 2018-08-27T11:26:46.714Z. Now: 2018-08-28T11:26:46.168Z
[junit4] 2> 1939445 INFO (TEST-ScheduledTriggerTest.testIgnoredEvent-seed#[5C4CFF49386EFD09]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testIgnoredEvent
[junit4] 2> 1939457 INFO (TEST-ScheduledTriggerTest.testTrigger-seed#[5C4CFF49386EFD09]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTrigger
[junit4] 2> 1940362 DEBUG (ScheduledTrigger-6168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1941362 DEBUG (ScheduledTrigger-6168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1942362 DEBUG (ScheduledTrigger-6168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1943362 DEBUG (ScheduledTrigger-6168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1944363 DEBUG (ScheduledTrigger-6168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1945363 DEBUG (ScheduledTrigger-6168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1945458 WARN (TEST-ScheduledTriggerTest.testTrigger-seed#[5C4CFF49386EFD09]) [ ] o.a.s.c.a.ScheduledTrigger ScheduledTrigger was not able to run event at scheduled time: 2018-08-28T11:26:49.729Z. Now: 2018-08-28T11:26:52.183Z
[junit4] 2> 1946363 DEBUG (ScheduledTrigger-6168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1947363 DEBUG (ScheduledTrigger-6168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1948363 DEBUG (ScheduledTrigger-6168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1948459 WARN (TEST-ScheduledTriggerTest.testTrigger-seed#[5C4CFF49386EFD09]) [ ] o.a.s.c.a.ScheduledTrigger ScheduledTrigger was not able to run event at scheduled time: 2018-08-28T11:26:52.729Z. Now: 2018-08-28T11:26:55.183Z
[junit4] 2> 1948460 INFO (TEST-ScheduledTriggerTest.testTrigger-seed#[5C4CFF49386EFD09]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ScheduledTriggerTest -Dtests.method=testTrigger -Dtests.seed=5C4CFF49386EFD09 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=Indian/Cocos -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 9.02s J1 | ScheduledTriggerTest.testTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<3> but was:<2>
[junit4] > at __randomizedtesting.SeedInfo.seed([5C4CFF49386EFD09:3F87C9CBA1A18E24]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.ScheduledTriggerTest.scheduledTriggerTest(ScheduledTriggerTest.java:113)
[junit4] > at org.apache.solr.cloud.autoscaling.ScheduledTriggerTest.testTrigger(ScheduledTriggerTest.java:66)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1948464 INFO (jetty-closer-8983-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@342ea6ab{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 1948465 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=168696144
[junit4] 2> 1948465 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1948465 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4d61918c: rootName = solr_34904, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@505b5f56
[junit4] 2> 1948471 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1948471 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@53e5e65b: rootName = solr_34904, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7b66ad63
[junit4] 2> 1948474 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1948474 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4eb84805: rootName = solr_34904, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3e642c6b
[junit4] 2> 1948475 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:34904_solr
[junit4] 2> 1948475 INFO (zkCallback-8999-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1948476 INFO (zkCallback-8992-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 1948476 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1948476 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1948476 INFO (jetty-closer-8983-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72237448824225795-127.0.0.1:34904_solr-n_0000000000) closing
[junit4] 2> 1948476 INFO (OverseerStateUpdate-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [n:127.0.0.1:34904_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:34904_solr
[junit4] 2> 1948477 WARN (OverseerAutoScalingTriggerThread-72237448824225795-127.0.0.1:34904_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1948477 DEBUG (jetty-closer-8983-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1948478 INFO (jetty-closer-8983-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@204b5dd6{/solr,null,UNAVAILABLE}
[junit4] 2> 1948479 INFO (jetty-closer-8983-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1948479 ERROR (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1948479 INFO (SUITE-ScheduledTriggerTest-seed#[5C4CFF49386EFD09]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46776 46776
[junit4] 2> 1948574 INFO (Thread-2689) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46776 46776
[junit4] 2> 1948574 WARN (Thread-2689) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledTriggerTest_5C4CFF49386EFD09-001
[junit4] 2> Aug 28, 2018 11:26:55 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=26497, maxDocsPerChunk=841, blockSize=337), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=26497, blockSize=337)), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6afb98eb), locale=ru, timezone=Indian/Cocos
[junit4] 2> NOTE: Linux 4.4.0-130-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=210717288,total=524812288
[junit4] 2> NOTE: All tests run in this JVM: [PreAnalyzedFieldManagedSchemaCloudTest, TestImpersonationWithHadoopAuth, TestGraphTermsQParserPlugin, HighlighterTest, TestMultiWordSynonyms, TestSweetSpotSimilarityFactory, PrimUtilsTest, TestInPlaceUpdatesDistrib, TestBackupRepositoryFactory, DeleteNodeTest, PKIAuthenticationIntegrationTest, TestManagedStopFilterFactory, TestPhraseSuggestions, ExternalFileFieldSortTest, LukeRequestHandlerTest, HDFSCollectionsAPITest, SolrMetricReporterTest, TestSimNodeAddedTrigger, MinimalSchemaTest, TestPullReplicaErrorHandling, TestSearchPerf, TestSlowCompositeReaderWrapper, ClassificationUpdateProcessorFactoryTest, SolrGraphiteReporterTest, MissingSegmentRecoveryTest, TestReplicationHandlerBackup, HdfsChaosMonkeyNothingIsSafeTest, TestRawTransformer, ShardRoutingTest, EmbeddedSolrNoSerializeTest, TestSolrConfigHandlerConcurrent, CloudMLTQParserTest, TestSimExecutePlanAction, TestUseDocValuesAsStored, TestClassicSimilarityFactory, TestIBSimilarityFactory, SolrInfoBeanTest, TestCryptoKeys, TestStressUserVersions, JsonLoaderTest, PeerSyncWithIndexFingerprintCachingTest, TestFieldResource, TestSQLHandler, HdfsCollectionsAPIDistributedZkTest, CollectionsAPIDistributedZkTest, DataDrivenBlockJoinTest, TestSolrCloudSnapshots, TriggerIntegrationTest, ShufflingReplicaListTransformerTest, TestFieldCacheReopen, BadCopyFieldTest, TestAnalyzedSuggestions, DOMUtilTest, TestTolerantSearch, TestJmxIntegration, ConjunctionSolrSpellCheckerTest, RequestLoggingTest, TestDistributedMap, CdcrRequestHandlerTest, TestChildDocTransformer, TestLuceneIndexBackCompat, SolrRrdBackendFactoryTest, SolrCLIZkUtilsTest, TestExpandComponent, TolerantUpdateProcessorTest, NodeMutatorTest, SuggestComponentContextFilterQueryTest, TestSubQueryTransformerDistrib, TestMacros, TestReRankQParserPlugin, TestSolrQueryParser, TestSchemaVersionResource, TestUnInvertedFieldException, SSLMigrationTest, TestJsonFacetsStatsParsing, TestCloudDeleteByQuery, TestNRTOpen, TestSortByMinMaxFunction, HdfsSyncSliceTest, TestTrackingShardHandlerFactory, SpatialFilterTest, CloneFieldUpdateProcessorFactoryTest, LegacyCloudClusterPropTest, DistributedDebugComponentTest, RAMDirectoryFactoryTest, TestLegacyNumericRangeQueryBuilder, TestNestedUpdateProcessor, TimeZoneUtilsTest, BadComponentTest, BufferStoreTest, NoCacheHeaderTest, GraphQueryTest, TestTolerantUpdateProcessorRandomCloud, MetricsConfigTest, BasicDistributedZkTest, QueryEqualityTest, TestSolrIndexConfig, TestStressLiveNodes, TestFreeTextSuggestions, CSVRequestHandlerTest, ManagedSchemaRoundRobinCloudTest, TestReversedWildcardFilterFactory, MaxSizeAutoCommitTest, TestImplicitCoreProperties, TestCursorMarkWithoutUniqueKey, TestComplexPhraseLeadingWildcard, TestSolrCoreParser, CacheHeaderTest, AlternateDirectoryTest, TestClusterStateMutator, TestSystemIdResolver, BlockJoinFacetDistribTest, SystemInfoHandlerTest, AssignBackwardCompatibilityTest, RemoteQueryErrorTest, DistributedFacetPivotLargeTest, TestCloudJSONFacetSKG, TestRTimerTree, TestConfigSetProperties, TestCloudRecovery, TestFunctionQuery, TestFastOutputStream, LeaderFailureAfterFreshStartTest, DistributedQueryComponentCustomSortTest, NumericFieldsTest, SpatialHeatmapFacetsTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, BitVectorTest, PeerSyncReplicationTest, OverseerCollectionConfigSetProcessorTest, DistributedFacetPivotSmallTest, SpellPossibilityIteratorTest, TestCollectionAPI, ScheduledTriggerTest]
[junit4] Completed [486/830 (1!)] on J1 in 10.00s, 2 tests, 1 failure <<< FAILURES!
[...truncated 49790 lines...]
[asciidoctor:convert] asciidoctor: ERROR: about-this-guide.adoc: line 1: invalid part, must have at least one section (e.g., chapter, appendix, etc.)
[asciidoctor:convert] asciidoctor: ERROR: solr-glossary.adoc: line 1: invalid part, must have at least one section (e.g., chapter, appendix, etc.)
[java] Processed 2308 links (1861 relative) to 3131 anchors in 246 files
[echo] Validated Links & Anchors via: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-ref-guide/bare-bones-html/
-documentation-lint:
[jtidy] Checking for broken html (such as invalid tags)...
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/build/jtidy_tmp
[echo] Checking for broken links...
[exec]
[exec] Crawl/parse...
[exec]
[exec] Verify...
[echo] Checking for malformed docs...
jar-checksums:
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/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-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
common.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-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1211461397
[copy] Copying 35 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1211461397
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1211461397
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 = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/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 = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/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 = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null2092480485
[copy] Copying 238 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null2092480485
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null2092480485
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 37ms :: artifacts dl 3ms
---------------------------------------------------------------------
| | 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: 94 minutes 2 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$34.hasMatch(FilePath.java:2678)
at hudson.FilePath$34.invoke(FilePath.java:2557)
at hudson.FilePath$34.invoke(FilePath.java:2547)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1036)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1038)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)