You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/01/30 06:16:26 UTC
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk-9) - Build # 4415 -
Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4415/
Java: 64bit/jdk-9 -XX:-UseCompressedOops -XX:+UseSerialGC
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.analytics.OverallAnalyticsTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.analytics.OverallAnalyticsTest: 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest] at java.base@9/jdk.internal.misc.Unsafe.park(Native Method) at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708) at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) at java.base@9/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.analytics.OverallAnalyticsTest:
1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.base@9/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([52209ED3420A94E7]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.analytics.OverallAnalyticsTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest] at java.base@9/jdk.internal.misc.Unsafe.park(Native Method) at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234) at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708) at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) at java.base@9/java.lang.Thread.run(Thread.java:844)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.base@9/java.lang.Thread.run(Thread.java:844)
at __randomizedtesting.SeedInfo.seed([52209ED3420A94E7]:0)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate
Error Message:
{srt=[CapturedEvent{timestamp=1044782017928525, stage=AFTER_ACTION, actionName='compute', event={ "id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185", "source":"search_rate_trigger", "eventTime":1044778799023475, "eventType":"SEARCHRATE", "properties":{ "node":{ "127.0.0.1:10016_solr":250.0, "127.0.0.1:10013_solr":250.0}, "__start__":1, "replica":[ "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], "collection":{"collection1":500.0}, "shard":{"collection1":{"shard1":500.0}}, "_enqueue_time_":1044781914036225, "requestedOps":[ "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute], source=search_rate_trigger, properties.AFTER_ACTION=[compute]}, config={ "trigger":"search_rate_trigger", "stage":[ "FAILED", "SUCCEEDED"], "afterAction":[ "compute", "execute", "test"], "class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener", "beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784243661125, stage=AFTER_ACTION, actionName='execute', event={ "id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185", "source":"search_rate_trigger", "eventTime":1044778799023475, "eventType":"SEARCHRATE", "properties":{ "node":{ "127.0.0.1:10016_solr":250.0, "127.0.0.1:10013_solr":250.0}, "__start__":1, "replica":[ "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], "collection":{"collection1":500.0}, "shard":{"collection1":{"shard1":500.0}}, "_enqueue_time_":1044781914036225, "requestedOps":[ "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute, execute], properties.responses=[{status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}], source=search_rate_trigger, properties.AFTER_ACTION=[compute, execute]}, config={ "trigger":"search_rate_trigger", "stage":[ "FAILED", "SUCCEEDED"], "afterAction":[ "compute", "execute", "test"], "class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener", "beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784252198475, stage=AFTER_ACTION, actionName='test', event={ "id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185", "source":"search_rate_trigger", "eventTime":1044778799023475, "eventType":"SEARCHRATE", "properties":{ "node":{ "127.0.0.1:10016_solr":250.0, "127.0.0.1:10013_solr":250.0}, "__start__":1, "replica":[ "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], "collection":{"collection1":500.0}, "shard":{"collection1":{"shard1":500.0}}, "_enqueue_time_":1044781914036225, "requestedOps":[ "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute, execute, test], properties.responses=[{status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}], source=search_rate_trigger, properties.AFTER_ACTION=[compute, execute, test]}, config={ "trigger":"search_rate_trigger", "stage":[ "FAILED", "SUCCEEDED"], "afterAction":[ "compute", "execute", "test"], "class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener", "beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784257796925, stage=SUCCEEDED, actionName='null', event={ "id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185", "source":"search_rate_trigger", "eventTime":1044778799023475, "eventType":"SEARCHRATE", "properties":{ "node":{ "127.0.0.1:10016_solr":250.0, "127.0.0.1:10013_solr":250.0}, "__start__":1, "replica":[ "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], "collection":{"collection1":500.0}, "shard":{"collection1":{"shard1":500.0}}, "_enqueue_time_":1044781914036225, "requestedOps":[ "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={}, config={ "trigger":"search_rate_trigger", "stage":[ "FAILED", "SUCCEEDED"], "afterAction":[ "compute", "execute", "test"], "class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener", "beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044789475113175, stage=AFTER_ACTION, actionName='compute', event={ "id":"3b6393b28634bT6lejbeoqu6skdmmwimmhol188", "source":"search_rate_trigger", "eventTime":1044781852025675, "eventType":"SEARCHRATE", "properties":{ "node":{ "127.0.0.1:10016_solr":250.0, "127.0.0.1:10013_solr":250.0}, "__start__":1, "replica":[ "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], "collection":{"collection1":500.0}, "shard":{"collection1":{"shard1":500.0}}, "_enqueue_time_":1044789345167425, "requestedOps":[ "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}", "Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute], source=search_rate_trigger, properties.AFTER_ACTION=[compute]}, config={ "trigger":"search_rate_trigger", "stage":[ "FAILED", "SUCCEEDED"], "afterAction":[ "compute", "execute", "test"], "class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener", "beforeAction":[]}, message='null'}]} expected:<4> but was:<5>
Stack Trace:
java.lang.AssertionError: {srt=[CapturedEvent{timestamp=1044782017928525, stage=AFTER_ACTION, actionName='compute', event={
"id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185",
"source":"search_rate_trigger",
"eventTime":1044778799023475,
"eventType":"SEARCHRATE",
"properties":{
"node":{
"127.0.0.1:10016_solr":250.0,
"127.0.0.1:10013_solr":250.0},
"__start__":1,
"replica":[
"{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
"{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
"collection":{"collection1":500.0},
"shard":{"collection1":{"shard1":500.0}},
"_enqueue_time_":1044781914036225,
"requestedOps":[
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute], source=search_rate_trigger, properties.AFTER_ACTION=[compute]}, config={
"trigger":"search_rate_trigger",
"stage":[
"FAILED",
"SUCCEEDED"],
"afterAction":[
"compute",
"execute",
"test"],
"class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener",
"beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784243661125, stage=AFTER_ACTION, actionName='execute', event={
"id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185",
"source":"search_rate_trigger",
"eventTime":1044778799023475,
"eventType":"SEARCHRATE",
"properties":{
"node":{
"127.0.0.1:10016_solr":250.0,
"127.0.0.1:10013_solr":250.0},
"__start__":1,
"replica":[
"{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
"{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
"collection":{"collection1":500.0},
"shard":{"collection1":{"shard1":500.0}},
"_enqueue_time_":1044781914036225,
"requestedOps":[
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute, execute], properties.responses=[{status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}], source=search_rate_trigger, properties.AFTER_ACTION=[compute, execute]}, config={
"trigger":"search_rate_trigger",
"stage":[
"FAILED",
"SUCCEEDED"],
"afterAction":[
"compute",
"execute",
"test"],
"class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener",
"beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784252198475, stage=AFTER_ACTION, actionName='test', event={
"id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185",
"source":"search_rate_trigger",
"eventTime":1044778799023475,
"eventType":"SEARCHRATE",
"properties":{
"node":{
"127.0.0.1:10016_solr":250.0,
"127.0.0.1:10013_solr":250.0},
"__start__":1,
"replica":[
"{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
"{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
"collection":{"collection1":500.0},
"shard":{"collection1":{"shard1":500.0}},
"_enqueue_time_":1044781914036225,
"requestedOps":[
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.async=search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0, params.waitForFinalState=true, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10016_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute, execute, test], properties.responses=[{status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}, {status={state=completed,msg=found [search_rate_trigger/3b638852f4573T6lejbeoqu6skdmmwimmhol185/0] in completed tasks},success=}], source=search_rate_trigger, properties.AFTER_ACTION=[compute, execute, test]}, config={
"trigger":"search_rate_trigger",
"stage":[
"FAILED",
"SUCCEEDED"],
"afterAction":[
"compute",
"execute",
"test"],
"class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener",
"beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044784257796925, stage=SUCCEEDED, actionName='null', event={
"id":"3b638852f4573T6lejbeoqu6skdmmwimmhol185",
"source":"search_rate_trigger",
"eventTime":1044778799023475,
"eventType":"SEARCHRATE",
"properties":{
"node":{
"127.0.0.1:10016_solr":250.0,
"127.0.0.1:10013_solr":250.0},
"__start__":1,
"replica":[
"{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
"{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
"collection":{"collection1":500.0},
"shard":{"collection1":{"shard1":500.0}},
"_enqueue_time_":1044781914036225,
"requestedOps":[
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={}, config={
"trigger":"search_rate_trigger",
"stage":[
"FAILED",
"SUCCEEDED"],
"afterAction":[
"compute",
"execute",
"test"],
"class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener",
"beforeAction":[]}, message='null'}, CapturedEvent{timestamp=1044789475113175, stage=AFTER_ACTION, actionName='compute', event={
"id":"3b6393b28634bT6lejbeoqu6skdmmwimmhol188",
"source":"search_rate_trigger",
"eventTime":1044781852025675,
"eventType":"SEARCHRATE",
"properties":{
"node":{
"127.0.0.1:10016_solr":250.0,
"127.0.0.1:10013_solr":250.0},
"__start__":1,
"replica":[
"{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10016_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
"{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":1000000000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10013_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
"collection":{"collection1":500.0},
"shard":{"collection1":{"shard1":500.0}},
"_enqueue_time_":1044789345167425,
"requestedOps":[
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}",
"Op{action=ADDREPLICA, hints={COLL_SHARD={\n \"first\":\"collection1\",\n \"second\":\"shard1\"}}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica, method=GET, params.action=ADDREPLICA, params.collection=collection1, params.shard=shard1, params.node=127.0.0.1:10013_solr, params.type=NRT}], properties.BEFORE_ACTION=[compute], source=search_rate_trigger, properties.AFTER_ACTION=[compute]}, config={
"trigger":"search_rate_trigger",
"stage":[
"FAILED",
"SUCCEEDED"],
"afterAction":[
"compute",
"execute",
"test"],
"class":"org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerListener",
"beforeAction":[]}, message='null'}]} expected:<4> but was:<5>
at __randomizedtesting.SeedInfo.seed([D1BC188EC38B7886:8CF406070C4DDEC9]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate(TestTriggerIntegration.java:1183)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at 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.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 13540 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_D1BC188EC38B7886-001/init-core-data-001
[junit4] 2> 3085570 INFO (SUITE-TestTriggerIntegration-seed#[D1BC188EC38B7886]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 3085571 INFO (SUITE-TestTriggerIntegration-seed#[D1BC188EC38B7886]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 3085571 INFO (SUITE-TestTriggerIntegration-seed#[D1BC188EC38B7886]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3085572 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3085572 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 3085572 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085572 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 3085573 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 3085573 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 3085573 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 3085573 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3085573 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3085573 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 3085573 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 3085573 DEBUG (ScheduledTrigger-12513-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085574 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3085574 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3085574 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3085574 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1247)
[junit4] 2> at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 3085575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3085576 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3085576 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085602 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085635 DEBUG (ScheduledTrigger-12516-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085666 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085684 DEBUG (simCloudManagerPool-12515-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3085685 DEBUG (simCloudManagerPool-12515-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3085685 DEBUG (simCloudManagerPool-12515-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085685 DEBUG (simCloudManagerPool-12515-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085685 DEBUG (simCloudManagerPool-12515-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3085685 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3085685 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3085686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3085686 DEBUG (ScheduledTrigger-12516-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3085686 DEBUG (ScheduledTrigger-12516-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3085686 DEBUG (ScheduledTrigger-12516-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10013_solr at time 1044725189097425
[junit4] 2> 3085686 DEBUG (ScheduledTrigger-12516-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3085713 DEBUG (ScheduledTrigger-12516-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3085713 DEBUG (ScheduledTrigger-12516-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3085713 DEBUG (ScheduledTrigger-12516-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10013_solr] added at times [1044725189097425], now=1044727746418275
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3b62c09c8b7d1T6lejbeoqu6skdmmwimmhol17q",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1044725189097425,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044725189097425],
[junit4] 2> "nodeNames":["127.0.0.1:10013_solr"]}}
[junit4] 2> 3085737 DEBUG (ScheduledTrigger-12516-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 3085738 DEBUG (AutoscalingActionExecutor-12517-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3b62c09c8b7d1T6lejbeoqu6skdmmwimmhol17q",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1044725189097425,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044725189097425],
[junit4] 2> "_enqueue_time_":1044727763214875,
[junit4] 2> "nodeNames":["127.0.0.1:10013_solr"]}}
[junit4] 2> 3085739 DEBUG (AutoscalingActionExecutor-12517-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3085739 DEBUG (AutoscalingActionExecutor-12517-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 3085739 DEBUG (AutoscalingActionExecutor-12517-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 42 ms for event id=3b62c09c8b7d1T6lejbeoqu6skdmmwimmhol17q
[junit4] 2> 3085739 DEBUG (simCloudManagerPool-12515-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3085739 DEBUG (simCloudManagerPool-12515-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3085739 DEBUG (simCloudManagerPool-12515-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085739 DEBUG (simCloudManagerPool-12515-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085740 DEBUG (simCloudManagerPool-12515-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3085740 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3085740 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 3085784 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 3085785 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3085786 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
[junit4] 2> 3085786 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3085786 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 3085788 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCooldown
[junit4] 2> 3085788 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 3085788 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3085789 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3085789 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3085789 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3085789 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3085789 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1247)
[junit4] 2> at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3085790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 3085790 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085819 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085850 DEBUG (ScheduledTrigger-12519-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085879 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085900 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3085900 DEBUG (simCloudManagerPool-12518-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3085900 DEBUG (simCloudManagerPool-12518-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 3085901 DEBUG (simCloudManagerPool-12518-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085901 DEBUG (simCloudManagerPool-12518-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3085901 DEBUG (simCloudManagerPool-12518-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085901 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 3085901 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3085901 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 3085901 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 3085902 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3085903 DEBUG (simCloudManagerPool-12518-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3085903 DEBUG (simCloudManagerPool-12518-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 3085903 DEBUG (simCloudManagerPool-12518-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085903 DEBUG (simCloudManagerPool-12518-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 3085903 DEBUG (simCloudManagerPool-12518-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3085903 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 3085903 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3085930 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3085930 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 3085930 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3085930 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10014_solr at time 1044737419320175
[junit4] 2> 3085960 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 3085960 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 3085961 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 3085961 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10014_solr] added at times [1044737419320175], now=1044738930187625
[junit4] 2> 3085961 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3b62ee2c31b6fT6lejbeoqu6skdmmwimmhol17t",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":1044737419320175,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044737419320175],
[junit4] 2> "nodeNames":["127.0.0.1:10014_solr"]}}
[junit4] 2> 3085961 DEBUG (ScheduledTrigger-12519-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 3085962 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3b62ee2c31b6fT6lejbeoqu6skdmmwimmhol17t",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":1044737419320175,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044737419320175],
[junit4] 2> "_enqueue_time_":1044738952048925,
[junit4] 2> "nodeNames":["127.0.0.1:10014_solr"]}}
[junit4] 2> 3085963 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3085963 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_cooldown_trigger after 100ms
[junit4] 2> 3085963 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 63 ms for event id=3b62ee2c31b6fT6lejbeoqu6skdmmwimmhol17t
[junit4] 2> 3086073 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 3086073 DEBUG (ScheduledTrigger-12519-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 3086074 DEBUG (ScheduledTrigger-12519-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3086074 DEBUG (ScheduledTrigger-12519-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10015_solr at time 1044744583579625
[junit4] 2> 3086105 DEBUG (ScheduledTrigger-12519-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 3086105 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 3086105 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 3086106 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10015_solr] added at times [1044744583579625], now=1044746176894025
[junit4] 2> 3086106 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3b6308dc907e9T6lejbeoqu6skdmmwimmhol17w",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":1044744583579625,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044744583579625],
[junit4] 2> "nodeNames":["127.0.0.1:10015_solr"]}}
[junit4] 2> 3086106 DEBUG (ScheduledTrigger-12519-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 3086106 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3b6308dc907e9T6lejbeoqu6skdmmwimmhol17w",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":1044744583579625,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044744583579625],
[junit4] 2> "_enqueue_time_":1044746187114025,
[junit4] 2> "nodeNames":["127.0.0.1:10015_solr"]}}
[junit4] 2> 3086107 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3086107 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_cooldown_trigger after 100ms
[junit4] 2> 3086107 DEBUG (AutoscalingActionExecutor-12520-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 41 ms for event id=3b6308dc907e9T6lejbeoqu6skdmmwimmhol17w
[junit4] 2> 3086161 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCooldown
[junit4] 2> 3086161 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3086161 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3086161 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 4
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 4
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_cooldown_trigger
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 2
[junit4] 2> 3086162 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 2
[junit4] 2> 3086165 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 3086165 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 3086165 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 3086165 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3086165 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3086166 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086166 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3086166 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1247)
[junit4] 2> at java.base/java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion -1
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086167 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 3086167 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086191 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086222 DEBUG (ScheduledTrigger-12522-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086247 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086276 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086277 DEBUG (simCloudManagerPool-12521-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3086277 DEBUG (simCloudManagerPool-12521-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 3086277 DEBUG (simCloudManagerPool-12521-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3086277 DEBUG (simCloudManagerPool-12521-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3086278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 3086278 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3086278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 3086278 DEBUG (ScheduledTrigger-12522-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3086278 DEBUG (ScheduledTrigger-12522-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10011_solr
[junit4] 2> 3086305 DEBUG (ScheduledTrigger-12522-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3086305 DEBUG (ScheduledTrigger-12522-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10011_solr
[junit4] 2> 3086305 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3086335 DEBUG (ScheduledTrigger-12522-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3086335 DEBUG (ScheduledTrigger-12522-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3086365 DEBUG (ScheduledTrigger-12522-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3086365 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3086365 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10011_solr]
[junit4] 2> 3086365 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3b632ef3e1625T6lejbeoqu6skdmmwimmhol17z",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1044754808575525,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044754808575525],
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"]}}
[junit4] 2> 3086366 DEBUG (ScheduledTrigger-12522-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_lost_trigger]
[junit4] 2> 3086367 DEBUG (AutoscalingActionExecutor-12523-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3b632ef3e1625T6lejbeoqu6skdmmwimmhol17z",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1044754808575525,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044754808575525],
[junit4] 2> "_enqueue_time_":1044759188643375,
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"]}}
[junit4] 2> 3086367 DEBUG (AutoscalingActionExecutor-12523-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3086367 DEBUG (AutoscalingActionExecutor-12523-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 3086367 DEBUG (AutoscalingActionExecutor-12523-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 37 ms for event id=3b632ef3e1625T6lejbeoqu6skdmmwimmhol17z
[junit4] 2> 3086368 DEBUG (simCloudManagerPool-12521-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3086368 DEBUG (simCloudManagerPool-12521-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 3086368 DEBUG (simCloudManagerPool-12521-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr]
[junit4] 2> 3086368 DEBUG (simCloudManagerPool-12521-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10013_solr]
[junit4] 2> 3086368 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 3086368 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086368 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTrigger
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 3086418 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10011_solr
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3086419 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 3086421 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[D1BC188EC38B7886]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 3086422 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 3086422 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 3086422 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3086422 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086422 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10011_solr
[junit4] 2> 3086422 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3086422 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 3086422 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2057)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:166)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 3086423 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[D1BC188EC38B7886]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10016_solr, 127.0.0.1:10013_solr]
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086424 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 3086425 DEBUG (ScheduledTrigger-12525-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086448 DEBUG (ScheduledTrigger-12525-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086479 DEBUG (ScheduledTrigger-12525-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086508 DEBUG (ScheduledTrigger-12525-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086533 DEBUG (ScheduledTrigger-12525-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086534 DEBUG (simCloudManagerPool-12524-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3086534 DEBUG (simCloudManagerPool-12524-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 3086535 DEBUG (simCloudManagerPool-12524-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10016_solr, 127.0.0.1:10013_solr, 127.0.0.1:10017_solr]
[junit4] 2> 3086535 DEBUG (simCloudManagerPool-12524-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10016_solr, 127.0.0.1:10013_solr, 127.0.0.1:10017_solr]
[junit4] 2> 3086535 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 3086535 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3086535 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086535 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 3086535 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2
[junit4] 2> 3086535 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10017_solr
[junit4] 2> 3086554 DEBUG (ScheduledTrigger-12525-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3086557 DEBUG (ScheduledTrigger-12525-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2
[junit4] 2> 3086567 DEBUG (simCloudManagerPool-12524-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3086567 DEBUG (simCloudManagerPool-12524-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 3086567 DEBUG (simCloudManagerPool-12524-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10016_solr, 127.0.0.1:10013_solr]
[junit4] 2> 3086567 DEBUG (simCloudManagerPool-12524-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10016_solr, 127.0.0.1:10013_solr]
[junit4] 2> 3086567 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 3086567 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 3086567 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3086567 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 3086567 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2
[junit4] 2> 3086567 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10017_solr]
[junit4] 2> 3086568 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3b635ed61cabfT6lejbeoqu6skdmmwimmhol182",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":1044767662262975,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1044767662262975],
[junit4] 2> "nodeNames":["127.0.0.1:10017_solr"]}}
[junit4] 2> 3086568 DEBUG (ScheduledTrigger-12525-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_lost_restore_trigger]
[junit4] 2> 3086569 DEBUG (AutoscalingActionExecutor-12526-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3b635ed61cabfT6lejbeoqu6skdmmwimmhol182",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":1044767662262975,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[10447
[...truncated too long message...]
ons, SimpleFacetsTest, StatsComponentTest, TestGroupingSearch, BasicFunctionalityTest, DirectUpdateHandlerTest, ShowFileRequestHandlerTest, SignatureUpdateProcessorFactoryTest, TestFoldingMultitermQuery, SuggesterTSTTest, SuggesterWFSTTest, SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, SortByFunctionTest, DocValuesMultiTest, DistanceFunctionTest, XsltUpdateRequestHandlerTest, TestReversedWildcardFilterFactory, RequestHandlersTest, DocumentBuilderTest, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestCSVResponseWriter, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, TestComponentsName, TestLFUCache, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, TestFastLRUCache, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, TestSolrJ, TestLRUCache, ZkNodePropsTest, SystemInfoHandlerTest, UUIDFieldTest, DistributedMLTComponentTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestHighlightDedupGrouping, TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, AddReplicaTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, DeleteInactiveReplicaTest, DeleteNodeTest, DeleteReplicaTest, DistribJoinFromCollectionTest, HealthCheckHandlerTest, LIRRollingUpdatesTest, MissingSegmentRecoveryTest, MultiThreadedOCPTest, ReplaceNodeTest, SolrXmlInZkTest, TestAuthenticationFramework, TestCloudDeleteByQuery, TestCloudInspectUtil, TestCloudJSONFacetJoinDomain, TestCloudPseudoReturnFields, TestClusterProperties, TestConfigSetsAPIZkFailure, TestDeleteCollectionOnDownNodes, TestLeaderElectionWithEmptyReplica, TestLeaderInitiatedRecoveryThread, TestRandomFlRTGCloud, TestRandomRequestDistribution, TestSSLRandomization, TestSolrCloudWithDelegationTokens, TestSolrCloudWithSecureImpersonation, TestStressLiveNodes, TestTolerantUpdateProcessorCloud, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, AssignTest, SimpleCollectionCreateDeleteTest, TestLocalFSCloudBackupRestore, AutoScalingHandlerTest, ExecutePlanActionTest, HdfsAutoAddReplicasIntegrationTest, SystemLogListenerTest, TestClusterStateProvider, TestDistribStateManager, TestGenericDistributedQueue, TestSimDistributedQueue, TestTriggerIntegration]
[junit4] Completed [588/773 (1!)] on J1 in 3.63s, 11 tests, 1 failure <<< FAILURES!
[...truncated 3730 lines...]
[junit4] Suite: org.apache.solr.analytics.OverallAnalyticsTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/contrib/solr-analytics/test/J0/temp/solr.analytics.OverallAnalyticsTest_52209ED3420A94E7-001/init-core-data-001
[junit4] 2> Jan 30, 2018 6:07:46 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> Jan 30, 2018 6:08:06 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.analytics.OverallAnalyticsTest:
[junit4] 2> 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
[junit4] 2> at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
[junit4] 2> at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.base@9/java.lang.Thread.run(Thread.java:844)
[junit4] 2> Jan 30, 2018 6:08:06 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
[junit4] 2> Jan 30, 2018 6:08:09 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
[junit4] 2> at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] 2> at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] 2> at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
[junit4] 2> at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.base@9/java.lang.Thread.run(Thread.java:844)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {string_s=PostingsFormat(name=MockRandom), id=BlockTreeOrds(blocksize=128), string_sm=Lucene50(blocksize=128)}, docValues:{int_i=DocValuesFormat(name=Asserting), double_dm=DocValuesFormat(name=Memory), float_fm=DocValuesFormat(name=Lucene70), int_im=DocValuesFormat(name=Lucene70), date_dt=DocValuesFormat(name=Asserting), date_dtm=DocValuesFormat(name=Direct), long_lm=DocValuesFormat(name=Direct), double_d=DocValuesFormat(name=Lucene70), float_f=DocValuesFormat(name=Memory), long_l=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Direct), string_s=DocValuesFormat(name=Asserting), id=DocValuesFormat(name=Memory), string_sm=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1406, maxMBSortInHeap=5.042074920574478, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1aafae87), locale=mgo, timezone=America/New_York
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 (64-bit)/cpus=3,threads=2,free=33909272,total=98959360
[junit4] 2> NOTE: All tests run in this JVM: [LegacyNoFacetTest, CastingDoubleValueTest, BottomFunctionTest, GTFunctionTest, CastingFloatValueTest, OverallAnalyticsTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverallAnalyticsTest -Dtests.seed=52209ED3420A94E7 -Dtests.slow=true -Dtests.locale=mgo -Dtests.timezone=America/New_York -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | OverallAnalyticsTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.analytics.OverallAnalyticsTest:
[junit4] > 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
[junit4] > at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
[junit4] > at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.base@9/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([52209ED3420A94E7]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=66, name=qtp1315797791-66, state=TIMED_WAITING, group=TGRP-OverallAnalyticsTest]
[junit4] > at java.base@9/jdk.internal.misc.Unsafe.park(Native Method)
[junit4] > at java.base@9/java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:234)
[junit4] > at java.base@9/java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2192)
[junit4] > at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at app//org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at app//org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at app//org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.base@9/java.lang.Thread.run(Thread.java:844)
[junit4] > at __randomizedtesting.SeedInfo.seed([52209ED3420A94E7]:0)
[junit4] Completed [59/78 (1!)] on J0 in 58.02s, 1 test, 2 errors <<< FAILURES!
[...truncated 37733 lines...]