Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/1155/
2 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest.testInactiveMarkersCleanup
Error Message:
marker for nodeAdded doesn't exist
Stack Trace:
java.lang.AssertionError: marker for nodeAdded doesn't exist
at
__randomizedtesting.SeedInfo.seed([BEB7EF11F7037B80:73F7308910FB1159]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at
org.apache.solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest.testInactiveMarkersCleanup(ScheduledMaintenanceTriggerTest.java:372)
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:1750)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimLargeCluster.testAddNode
Error Message:
no MOVEREPLICA ops?
Stack Trace:
java.lang.AssertionError: no MOVEREPLICA ops?
at
__randomizedtesting.SeedInfo.seed([BEB7EF11F7037B80:1958F2B2384EF498]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at
org.apache.solr.cloud.autoscaling.sim.TestSimLargeCluster.testAddNode(TestSimLargeCluster.java:322)
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:1750)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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 14487 lines...]
[junit4] Suite:
org.apache.solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest
[junit4] 2> 3297479 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest_BEB7EF11F7037B80-001/init-core-data-001
[junit4] 2> 3297480 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3297482 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-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> 3297482 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest_BEB7EF11F7037B80-001/tempDir-001
[junit4] 2> 3297499 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3297499 INFO (ZkTestServer Run Thread) [ ]
o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3297499 INFO (ZkTestServer Run Thread) [ ]
o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3297599 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:41231
[junit4] 2> 3297599 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:41231
[junit4] 2> 3297600 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1 41231
[junit4] 2> 3297607 INFO (zkConnectionManagerCallback-7468-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3297608 INFO (zkConnectionManagerCallback-7470-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3297617 INFO (zkConnectionManagerCallback-7472-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3297634 WARN (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 3297634 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 3297634 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 3297634 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git:
c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
[junit4] 2> 3297653 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3297653 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3297653 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 3297653 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@4cda6bae{/solr,null,AVAILABLE}
[junit4] 2> 3297655 WARN (jetty-launcher-7473-thread-1) [ ]
o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for
SslContextFactory@fe1459a[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@16853141{SSL,[ssl,
http/1.1]}{127.0.0.1:33166}
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.e.j.s.Server Started @3298063ms
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=33166}
[junit4] 2> 3297656 ERROR (jetty-launcher-7473-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter Using logger factory
org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.7.0
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3297656 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-12-25T08:17:49.662Z
[junit4] 2> 3297689 INFO (zkConnectionManagerCallback-7475-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3297690 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3298353 INFO (jetty-launcher-7473-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41231/solr
[junit4] 2> 3298366 INFO (zkConnectionManagerCallback-7479-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3298368 INFO (zkConnectionManagerCallback-7481-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3298650 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:33166_solr
[junit4] 2> 3298650 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.c.Overseer Overseer
(id=73896748529680389-127.0.0.1:33166_solr-n_0000000000) starting
[junit4] 2> 3298655 INFO (zkConnectionManagerCallback-7488-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3298657 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster
at 127.0.0.1:41231/solr ready
[junit4] 2> 3298657 INFO
(OverseerStateUpdate-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[n:127.0.0.1:33166_solr ] o.a.s.c.Overseer Starting to work on the main
queue : 127.0.0.1:33166_solr
[junit4] 2> 3298670 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and
.scheduled_maintenance triggers
[junit4] 2> 3298671 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:33166_solr
[junit4] 2> 3298671 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode
version 1
[junit4] 2> 3298671 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1,
lastZnodeVersion 0
[junit4] 2> 3298672 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto
znodeVersion 1
[junit4] 2> 3298672 INFO (zkCallback-7487-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3298672 INFO (zkCallback-7480-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3298740 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial
livenodes: [127.0.0.1:33166_solr]
[junit4] 2> 3298740 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded
markers
[junit4] 2> 3298755 DEBUG
(OverseerAutoScalingTriggerThread-73896748529680389-127.0.0.1:33166_solr-n_0000000000)
[ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1,
lastZnodeVersion 1
[junit4] 2> 3298765 DEBUG (ScheduledTrigger-7735-thread-1) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3298792 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.h.a.MetricsHistoryHandler No .system
collection, keeping metrics history in memory.
[junit4] 2> 3298862 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33166.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5c0a704d
[junit4] 2> 3298898 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33166.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5c0a704d
[junit4] 2> 3298898 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_33166.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5c0a704d
[junit4] 2> 3298899 INFO (jetty-launcher-7473-thread-1)
[n:127.0.0.1:33166_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest_BEB7EF11F7037B80-001/tempDir-001/node1/.
[junit4] 2> 3298952 INFO (zkConnectionManagerCallback-7494-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3298953 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3298970 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41231/solr ready
[junit4] 2> 3299007 DEBUG
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader:
127.0.0.1:10035_solr
[junit4] 2> 3299007 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and
.scheduled_maintenance triggers
[junit4] 2> 3299007 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode
version 1
[junit4] 2> 3299008 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 3299008 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 3299008 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial
livenodes: [127.0.0.1:10035_solr]
[junit4] 2> 3299009 DEBUG
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states,
currentVersion=0
[junit4] 2> 3299009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
[junit4] 2> 3299009 DEBUG
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 3299009 INFO
(SUITE-ScheduledMaintenanceTriggerTest-seed#[BEB7EF11F7037B80]-worker) [ ]
o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history
in memory.
[junit4] 2> 3299009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 3299009 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299030 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299050 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299070 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299095 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299115 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299135 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299156 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299176 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299196 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299216 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299236 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299248 INFO
(TEST-ScheduledMaintenanceTriggerTest.testInactiveMarkersCleanup-seed#[BEB7EF11F7037B80])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testInactiveMarkersCleanup
[junit4] 2> 3299249 DEBUG (simCloudManagerPool-7743-thread-1) [ ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3299249 DEBUG (simCloudManagerPool-7743-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version
2
[junit4] 2> 3299257 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299261 DEBUG (simCloudManagerPool-7743-thread-2) [ ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3299261 DEBUG (simCloudManagerPool-7743-thread-2) [ ]
o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version
3
[junit4] 2> 3299274 DEBUG (simCloudManagerPool-7743-thread-3) [ ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3299274 DEBUG (simCloudManagerPool-7743-thread-3) [ ]
o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version
4
[junit4] 2> 3299276 DEBUG (simCloudManagerPool-7743-thread-4) [ ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3299276 DEBUG (simCloudManagerPool-7743-thread-4) [ ]
o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version
5
[junit4] 2> 3299277 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3299277 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerCooldownPeriodSeconds from: 5 to: 1
[junit4] 2> 3299278 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 - Initial livenodes:
[127.0.0.1:10035_solr]
[junit4] 2> 3299278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 instantiated with
properties: {event=nodeAdded, waitFor=1, actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.ScheduledMaintenanceTriggerTest$TestTriggerAction2}],
enabled=true}
[junit4] 2> 3299278 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:26.658Z,
now=2018-12-26T18:31:38.154Z
[junit4] 2> 3299278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
[junit4] 2> 3299278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [
] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 3299278 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"642378bae865ecT2ud51jb571fclx3t64qvzas35",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186499109905900,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849098154}}
[junit4] 2> 3299278 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299285 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection .system,
currentVersion=1
[junit4] 2> 3299285 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states,
currentVersion=1
[junit4] 2> 3299285 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 3299295 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states,
currentVersion=2
[junit4] 2> 3299295 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 3299306 DEBUG (simCloudManagerPool-7743-thread-6) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states,
currentVersion=3
[junit4] 2> 3299307 DEBUG (simCloudManagerPool-7743-thread-6) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 3299307 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection .system,
currentVersion=4
[junit4] 2> 3299307 INFO (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.CloudTestUtils -- shards without leaders: [shard1]
[junit4] 2> 3299307 DEBUG (simCloudManagerPool-7743-thread-7) [ ]
o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1
(currentVersion=4): {"core_node1":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "node_name":"127.0.0.1:10035_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 3299309 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states,
currentVersion=4
[junit4] 2> 3299309 DEBUG (simCloudManagerPool-7743-thread-5) [ ]
o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 3299319 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"642378bae865ecT2ud51jb571fclx3t64qvzas35",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186499109905900,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849098154,
[junit4] 2> "_enqueue_time_":28186499137807700}}
[junit4] 2> 3299323 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299323 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299323 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299323 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 184 ms for event
id=642378bae865ecT2ud51jb571fclx3t64qvzas35
[junit4] 2> 3299346 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299346 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299346 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3299357 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:28.658Z,
now=2018-12-26T18:31:42.113Z
[junit4] 2> 3299357 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"642379a60e9b86T2ud51jb571fclx3t64qvzas38",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186503055055750,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849102113}}
[junit4] 2> 3299357 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299357 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"642379a60e9b86T2ud51jb571fclx3t64qvzas38",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186503055055750,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849102113,
[junit4] 2> "_enqueue_time_":28186503062886350}}
[junit4] 2> 3299358 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299358 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299358 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299358 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=642379a60e9b86T2ud51jb571fclx3t64qvzas38
[junit4] 2> 3299378 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299378 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:30.658Z,
now=2018-12-26T18:31:43.183Z
[junit4] 2> 3299379 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299379 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3299379 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"642379e6e81fceT2ud51jb571fclx3t64qvzas3b",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186504143052750,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849103183}}
[junit4] 2> 3299379 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299379 DEBUG
(TEST-ScheduledMaintenanceTriggerTest.testInactiveMarkersCleanup-seed#[BEB7EF11F7037B80])
[ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker:
/autoscaling/nodeAdded/127.0.0.1:10036_solr
[junit4] 2> 3299379 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"642379e6e81fceT2ud51jb571fclx3t64qvzas3b",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186504143052750,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849103183,
[junit4] 2> "_enqueue_time_":28186504149905300}}
[junit4] 2> 3299380 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299380 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299380 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299380 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 38 ms for event
id=642379e6e81fceT2ud51jb571fclx3t64qvzas3b
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 1
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:32.658Z,
now=2018-12-26T18:31:44.282Z
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10036_solr at time
28186505227277200
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a274ca5e4T2ud51jb571fclx3t64qvzas3e",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186505223382500,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849104282}}
[junit4] 2> 3299400 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299404 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237a274ca5e4T2ud51jb571fclx3t64qvzas3e",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186505223382500,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849104282,
[junit4] 2> "_enqueue_time_":28186505231814000}}
[junit4] 2> 3299405 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299405 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299405 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299405 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 37 ms for event
id=64237a274ca5e4T2ud51jb571fclx3t64qvzas3e
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:34.658Z,
now=2018-12-26T18:31:45.523Z
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186506467438650
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a714c2e9eT2ud51jb571fclx3t64qvzas3h",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186506464865950,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849105523}}
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299425 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas3i",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299426 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299427 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237a714c2e9eT2ud51jb571fclx3t64qvzas3h",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186506464865950,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849105523,
[junit4] 2> "_enqueue_time_":28186506472872950}}
[junit4] 2> 3299427 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299427 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299427 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299427 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=64237a714c2e9eT2ud51jb571fclx3t64qvzas3h
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:36.658Z,
now=2018-12-26T18:31:46.638Z
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237ab3ba79c0T2ud51jb571fclx3t64qvzas3m",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186507579390400,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849106638}}
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186507582358500
[junit4] 2> 3299447 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299448 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas3n",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299448 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299448 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237ab3ba79c0T2ud51jb571fclx3t64qvzas3m",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186507579390400,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849106638,
[junit4] 2> "_enqueue_time_":28186507586136600}}
[junit4] 2> 3299448 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299448 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299449 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299449 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 30 ms for event
id=64237ab3ba79c0T2ud51jb571fclx3t64qvzas3m
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:38.658Z,
now=2018-12-26T18:31:47.702Z
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237af31daf92T2ud51jb571fclx3t64qvzas3r",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186508642856850,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849107702}}
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186508646619650
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas3s",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299469 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299469 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237af31daf92T2ud51jb571fclx3t64qvzas3r",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186508642856850,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849107702,
[junit4] 2> "_enqueue_time_":28186508649354050}}
[junit4] 2> 3299473 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299473 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299473 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299473 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 195 ms for event
id=64237af31daf92T2ud51jb571fclx3t64qvzas3r
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:40.658Z,
now=2018-12-26T18:31:48.939Z
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186509881768200
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237b3cd813e8T2ud51jb571fclx3t64qvzas3w",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186509879809000,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849108939}}
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299493 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas3x",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299494 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299494 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237b3cd813e8T2ud51jb571fclx3t64qvzas3w",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186509879809000,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849108939,
[junit4] 2> "_enqueue_time_":28186509886602300}}
[junit4] 2> 3299495 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299495 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299495 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299495 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=64237b3cd813e8T2ud51jb571fclx3t64qvzas3w
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:42.658Z,
now=2018-12-26T18:31:50.018Z
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237b7d312880T2ud51jb571fclx3t64qvzas41",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186510959388800,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849110018}}
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186510977178650
[junit4] 2> 3299515 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas43",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299516 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237b7d312880T2ud51jb571fclx3t64qvzas41",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186510959388800,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849110018,
[junit4] 2> "_enqueue_time_":28186510966327850}}
[junit4] 2> 3299516 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299516 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299516 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299516 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299516 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 30 ms for event
id=64237b7d312880T2ud51jb571fclx3t64qvzas41
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:44.658Z,
now=2018-12-26T18:31:51.103Z
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186512044765050
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237bbdd1f220T2ud51jb571fclx3t64qvzas46",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186512043668000,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849111103}}
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas47",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers Ignoring event
64237a27881390T2ud51jb571fclx3t64qvzas47, already processing other actions.
[junit4] 2> 3299537 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237bbdd1f220T2ud51jb571fclx3t64qvzas46",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186512043668000,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849111103,
[junit4] 2> "_enqueue_time_":28186512049830450}}
[junit4] 2> 3299537 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299538 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299538 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299538 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299538 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 29 ms for event
id=64237bbdd1f220T2ud51jb571fclx3t64qvzas46
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:46.658Z,
now=2018-12-26T18:31:52.168Z
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186513111281600
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237bfd5507b6T2ud51jb571fclx3t64qvzas4b",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186513109223350,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849112168}}
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299558 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas4c",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299559 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299559 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237bfd5507b6T2ud51jb571fclx3t64qvzas4b",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186513109223350,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849112168,
[junit4] 2> "_enqueue_time_":28186513115839900}}
[junit4] 2> 3299559 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299559 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299559 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299559 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 33 ms for event
id=64237bfd5507b6T2ud51jb571fclx3t64qvzas4b
[junit4] 2> 3299579 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:48.658Z,
now=2018-12-26T18:31:53.250Z
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186514192099400
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237c3dcfedecT2ud51jb571fclx3t64qvzas4g",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186514191019500,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849113250}}
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas4h",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Ignoring event
64237a27881390T2ud51jb571fclx3t64qvzas4h, already processing other actions.
[junit4] 2> 3299580 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299580 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237c3dcfedecT2ud51jb571fclx3t64qvzas4g",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186514191019500,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849113250,
[junit4] 2> "_enqueue_time_":28186514197485200}}
[junit4] 2> 3299581 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299581 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299581 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299581 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=64237c3dcfedecT2ud51jb571fclx3t64qvzas4g
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:50.658Z,
now=2018-12-26T18:31:54.318Z
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237c7d7d2572T2ud51jb571fclx3t64qvzas4l",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186515259336050,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849114318}}
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186515262333800
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299601 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas4m",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299602 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299602 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237c7d7d2572T2ud51jb571fclx3t64qvzas4l",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186515259336050,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849114318,
[junit4] 2> "_enqueue_time_":28186515267143900}}
[junit4] 2> 3299602 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299602 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299602 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299602 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 29 ms for event
id=64237c7d7d2572T2ud51jb571fclx3t64qvzas4l
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:52.658Z,
now=2018-12-26T18:31:55.388Z
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186516332011400
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237cbd4bd16cT2ud51jb571fclx3t64qvzas4q",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186516329845100,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849115388}}
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299622 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas4r",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299623 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299627 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237cbd4bd16cT2ud51jb571fclx3t64qvzas4q",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186516329845100,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849115388,
[junit4] 2> "_enqueue_time_":28186516337072550}}
[junit4] 2> 3299650 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299650 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299650 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299650 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 1181 ms for event
id=64237cbd4bd16cT2ud51jb571fclx3t64qvzas4q
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:54.658Z,
now=2018-12-26T18:31:58.187Z
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186519129659400
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237d641770beT2ud51jb571fclx3t64qvzas4v",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186519128207550,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849118187}}
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas4w",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299678 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Ignoring event
64237a27881390T2ud51jb571fclx3t64qvzas4w, already processing other actions.
[junit4] 2> 3299679 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237d641770beT2ud51jb571fclx3t64qvzas4v",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186519128207550,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849118187,
[junit4] 2> "_enqueue_time_":28186519137829450}}
[junit4] 2> 3299679 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299680 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299680 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299680 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299680 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=64237d641770beT2ud51jb571fclx3t64qvzas4v
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:56.658Z,
now=2018-12-26T18:31:59.266Z
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186520210934950
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237da47221a4T2ud51jb571fclx3t64qvzas50",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186520207892900,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849119266}}
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas51",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299700 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers Ignoring event
64237a27881390T2ud51jb571fclx3t64qvzas51, already processing other actions.
[junit4] 2> 3299701 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299701 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237da47221a4T2ud51jb571fclx3t64qvzas50",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186520207892900,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849119266,
[junit4] 2> "_enqueue_time_":28186520221504850}}
[junit4] 2> 3299701 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299701 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299701 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299702 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event
id=64237da47221a4T2ud51jb571fclx3t64qvzas50
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:31:58.658Z,
now=2018-12-26T18:32:00.357Z
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186521299961700
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237de574f7daT2ud51jb571fclx3t64qvzas55",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186521298597850,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849120357}}
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-4) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas56",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers Ignoring event
64237a27881390T2ud51jb571fclx3t64qvzas56, already processing other actions.
[junit4] 2> 3299722 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299723 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237de574f7daT2ud51jb571fclx3t64qvzas55",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186521298597850,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849120357,
[junit4] 2> "_enqueue_time_":28186521305744900}}
[junit4] 2> 3299723 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299723 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299723 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299723 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 34 ms for event
id=64237de574f7daT2ud51jb571fclx3t64qvzas55
[junit4] 2> 3299743 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299743 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:32:00.658Z,
now=2018-12-26T18:32:01.444Z
[junit4] 2> 3299743 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[junit4] 2> 3299743 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3299744 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger trigger1 firing registered
processor for nodes: [127.0.0.1:10036_solr] added at times [28186505227277200],
now=28186522387649750
[junit4] 2> 3299744 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237e263d5b2cT2ud51jb571fclx3t64qvzas5a",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186522385472300,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849121444}}
[junit4] 2> 3299744 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299744 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"64237a27881390T2ud51jb571fclx3t64qvzas5b",
[junit4] 2> "source":"trigger1",
[junit4] 2> "eventTime":28186505227277200,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[28186505227277200],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10036_solr"]}}
[junit4] 2> 3299744 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10036_solr]!
[junit4] 2> 3299748 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237e263d5b2cT2ud51jb571fclx3t64qvzas5a",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186522385472300,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849121444,
[junit4] 2> "_enqueue_time_":28186522396179450}}
[junit4] 2> 3299781 DEBUG (ScheduledTrigger-7735-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 1 and last live nodes: 1
[junit4] 2> 3299781 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299781 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299781 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299781 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 1643 ms for event
id=64237e263d5b2cT2ud51jb571fclx3t64qvzas5a
[junit4] 2> 3299801 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299801 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:32:02.658Z,
now=2018-12-26T18:32:04.337Z
[junit4] 2> 3299801 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"64237ed2992e64T2ud51jb571fclx3t64qvzas5f",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186525277171300,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{"actualEventTime":1545849124337}}
[junit4] 2> 3299801 DEBUG (ScheduledTrigger-7744-thread-2) [ ]
o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas,
.scheduled_maintenance, trigger1]
[junit4] 2> 3299802 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"64237ed2992e64T2ud51jb571fclx3t64qvzas5f",
[junit4] 2> "source":".scheduled_maintenance",
[junit4] 2> "eventTime":28186525277171300,
[junit4] 2> "eventType":"SCHEDULED",
[junit4] 2> "properties":{
[junit4] 2> "actualEventTime":1545849124337,
[junit4] 2> "_enqueue_time_":28186525284870650}}
[junit4] 2> 3299803 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 20ms
[junit4] 2> 3299803 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 20ms
[junit4] 2> 3299803 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers Resuming trigger: trigger1 after 20ms
[junit4] 2> 3299803 DEBUG (AutoscalingActionExecutor-7745-thread-1) [ ]
o.a.s.c.a.ScheduledTriggers -- processing took 48 ms for event
id=64237ed2992e64T2ud51jb571fclx3t64qvzas5f
[junit4] 2> 3299849 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with
currently live nodes: 2 and last live nodes: 2
[junit4] 2> 3299849 DEBUG (ScheduledTrigger-7744-thread-1) [ ]
o.a.s.c.a.ScheduledTrigger ScheduledTrigger .scheduled_maintenance firing
registered processor for scheduled time 2018-12-26T18:32:04.658Z,
now=2018-12-26T18:32:06.721Z
[junit4] 2> 3299849 DEBUG (ScheduledTrigger-7744-thread-3) [ ]
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger trigger1
[...truncated too long message...]
operty disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file =
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/null712870502
[copy] Copying 242 files to
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/null712870502
[delete] Deleting directory
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/null712870502
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 20ms :: artifacts dl 5ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 8 | 0 | 0 | 0 || 8 | 0 |
---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for
further details.
[wc-checker] Checking working copy status...
-jenkins-base:
BUILD SUCCESSFUL
Total time: 197 minutes 38 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 lucene2
at
hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at
hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1036)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at
hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at
hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at
hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at
hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at
hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at
hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at
hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at
hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no
matches found within 10000
at hudson.FilePath.act(FilePath.java:1038)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at
hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at
hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at
hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at
hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern
"**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
