Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/ Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
3 tests failed. FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testTrigger Error Message: number of ops expected:<2> but was:<1> Stack Trace: java.lang.AssertionError: number of ops expected:<2> but was:<1> at __randomizedtesting.SeedInfo.seed([D9EB6F4461EDE612:BA2059C6F822953F]: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.IndexSizeTriggerTest.testTrigger(IndexSizeTriggerTest.java:187) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration Error Message: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/81)={ "replicationFactor":"2", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"2", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0", "autoCreated":"true", "shards":{ "shard2":{ "replicas":{ "core_node3":{ "core":"testSplitIntegration_collection_shard2_replica_n3", "leader":"true", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "stateTimestamp":"1524839346167963900", "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"inactive"}, "shard1_1":{ "parent":"shard1", "stateTimestamp":"1524839346202121800", "range":"c0000000-ffffffff", "state":"active", "replicas":{ "core_node10":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_1_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node9":{ "core":"testSplitIntegration_collection_shard1_1_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}, "shard1_0":{ "parent":"shard1", "stateTimestamp":"1524839346201908750", "range":"80000000-bfffffff", "state":"active", "replicas":{ "core_node7":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_0_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node8":{ "core":"testSplitIntegration_collection_shard1_0_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}}} Stack Trace: java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/81)={ "replicationFactor":"2", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"2", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0", "autoCreated":"true", "shards":{ "shard2":{ "replicas":{ "core_node3":{ "core":"testSplitIntegration_collection_shard2_replica_n3", "leader":"true", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "stateTimestamp":"1524839346167963900", "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"inactive"}, "shard1_1":{ "parent":"shard1", "stateTimestamp":"1524839346202121800", "range":"c0000000-ffffffff", "state":"active", "replicas":{ "core_node10":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_1_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node9":{ "core":"testSplitIntegration_collection_shard1_1_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}, "shard1_0":{ "parent":"shard1", "stateTimestamp":"1524839346201908750", "range":"80000000-bfffffff", "state":"active", "replicas":{ "core_node7":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_0_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node8":{ "core":"testSplitIntegration_collection_shard1_0_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}}} at __randomizedtesting.SeedInfo.seed([D9EB6F4461EDE612:E065D6044E122FEC]:0) at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111) at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:299) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.search.TestStressRecovery.testStressRecovery Error Message: Captured an uncaught exception in thread: Thread[id=25528, name=READER7, state=RUNNABLE, group=TGRP-TestStressRecovery] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=25528, name=READER7, state=RUNNABLE, group=TGRP-TestStressRecovery] at __randomizedtesting.SeedInfo.seed([D9EB6F4461EDE612:63D10619FE05591C]:0) Caused by: java.lang.RuntimeException: java.lang.NullPointerException at __randomizedtesting.SeedInfo.seed([D9EB6F4461EDE612]:0) at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:332) Caused by: java.lang.NullPointerException at org.apache.solr.update.TransactionLog.lookup(TransactionLog.java:521) at org.apache.solr.update.UpdateLog.lookup(UpdateLog.java:979) at org.apache.solr.handler.component.RealTimeGetComponent.process(RealTimeGetComponent.java:235) at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:295) at org.apache.solr.handler.RealTimeGetHandler.handleRequestBody(RealTimeGetHandler.java:46) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199) at org.apache.solr.core.SolrCore.execute(SolrCore.java:2510) at org.apache.solr.util.TestHarness.query(TestHarness.java:337) at org.apache.solr.util.TestHarness.query(TestHarness.java:319) at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:307) Build Log: [...truncated 13030 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest [junit4] 2> 686242 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_D9EB6F4461EDE612-001/init-core-data-001 [junit4] 2> 686243 WARN (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=135 numCloses=135 [junit4] 2> 686243 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 686245 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 686245 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_D9EB6F4461EDE612-001/tempDir-001 [junit4] 2> 686245 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 686245 INFO (Thread-1550) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 686245 INFO (Thread-1550) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 686247 ERROR (Thread-1550) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 686345 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:62647 [junit4] 2> 686348 INFO (zkConnectionManagerCallback-1886-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686353 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 686353 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T17:27:37-04:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 686354 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 686354 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 686354 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 686354 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 686354 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@35d67dd{/solr,null,AVAILABLE} [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@57aeb79c{/solr,null,AVAILABLE} [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@373c1dba{HTTP/1.1,[http/1.1]}{127.0.0.1:57618} [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@f2d0edb{HTTP/1.1,[http/1.1]}{127.0.0.1:64374} [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.e.j.s.Server Started @686778ms [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.e.j.s.Server Started @686778ms [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57618} [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64374} [junit4] 2> 686355 ERROR (jetty-launcher-1883-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 686355 ERROR (jetty-launcher-1883-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0 [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0 [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-27T14:28:04.352Z [junit4] 2> 686355 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-27T14:28:04.352Z [junit4] 2> 686357 INFO (zkConnectionManagerCallback-1888-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686358 INFO (zkConnectionManagerCallback-1890-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686358 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 686358 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 686372 INFO (jetty-launcher-1883-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62647/solr [junit4] 2> 686372 INFO (jetty-launcher-1883-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62647/solr [junit4] 2> 686374 INFO (zkConnectionManagerCallback-1896-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686374 INFO (zkConnectionManagerCallback-1898-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686377 INFO (zkConnectionManagerCallback-1900-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686377 INFO (zkConnectionManagerCallback-1902-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686505 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 686505 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 686506 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:64374_solr [junit4] 2> 686507 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57618_solr [junit4] 2> 686508 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.Overseer Overseer (id=72064496747544581-127.0.0.1:64374_solr-n_0000000000) starting [junit4] 2> 686508 INFO (zkCallback-1901-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 686509 INFO (zkCallback-1899-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 686516 INFO (zkConnectionManagerCallback-1911-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 686517 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 686518 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62647/solr ready [junit4] 2> 686520 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 686521 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 686521 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 686521 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 686522 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 686522 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64374_solr [junit4] 2> 686523 INFO (zkCallback-1899-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 686525 INFO (zkCallback-1910-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 686526 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:57618_solr, 127.0.0.1:64374_solr] [junit4] 2> 686527 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 686527 DEBUG (OverseerAutoScalingTriggerThread-72064496747544581-127.0.0.1:64374_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 686527 INFO (zkCallback-1901-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 686528 DEBUG (ScheduledTrigger-3100-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687190 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57618.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687195 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57618.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687195 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57618.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687196 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_D9EB6F4461EDE612-001/tempDir-001/node1/. [junit4] 2> 687200 INFO (zkConnectionManagerCallback-1916-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 687201 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 687203 INFO (jetty-launcher-1883-thread-1) [n:127.0.0.1:57618_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62647/solr ready [junit4] 2> 687482 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_64374.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687487 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_64374.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687487 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_64374.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@622185ce [junit4] 2> 687488 INFO (jetty-launcher-1883-thread-2) [n:127.0.0.1:64374_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_D9EB6F4461EDE612-001/tempDir-001/node2/. [junit4] 2> 687505 INFO (zkConnectionManagerCallback-1918-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 687510 INFO (zkConnectionManagerCallback-1923-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 687512 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 687514 INFO (SUITE-IndexSizeTriggerTest-seed#[D9EB6F4461EDE612]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62647/solr ready [junit4] 2> 687529 DEBUG (ScheduledTrigger-3100-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687545 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 687546 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0 [junit4] 2> 687546 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1 [junit4] 2> 687546 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0 [junit4] 2> 687549 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 687549 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 687549 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0 [junit4] 2> 687551 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687572 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687593 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687617 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687637 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687657 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687677 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687700 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687720 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687740 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687761 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687769 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[D9EB6F4461EDE612]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMergeIntegration [junit4] 2> 687781 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687801 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687821 DEBUG (ScheduledTrigger-3109-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687838 DEBUG (simCloudManagerPool-3108-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMergeIntegration_collection / shard2: {"core_node3":{ [junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n3", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"testMergeIntegration_collection"}} [junit4] 2> 687838 DEBUG (simCloudManagerPool-3108-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMergeIntegration_collection / shard1: {"core_node1":{ [junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testMergeIntegration_collection"}} [junit4] 2> 687842 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687856 DEBUG (simCloudManagerPool-3108-thread-19) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 687856 DEBUG (simCloudManagerPool-3108-thread-19) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 687857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 687857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 687857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 687862 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687863 DEBUG (simCloudManagerPool-3108-thread-20) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 687863 DEBUG (simCloudManagerPool-3108-thread-20) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 687863 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 687864 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 687864 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 687865 DEBUG (simCloudManagerPool-3108-thread-21) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 687865 DEBUG (simCloudManagerPool-3108-thread-21) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 687865 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 687865 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 687865 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 687882 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687903 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687923 DEBUG (ScheduledTrigger-3109-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687943 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687963 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 687986 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 688006 DEBUG (ScheduledTrigger-3109-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 688026 DEBUG (ScheduledTrigger-3109-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 688030 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} [junit4] 2> 688031 DEBUG (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger, .auto_add_replicas, .scheduled_maintenance] [junit4] 2> 688032 INFO (ScheduledTrigger-3109-thread-2) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353652568337, stage=STARTED, actionName='null', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688034 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} [junit4] 2> 688035 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353784254787, stage=BEFORE_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688035 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: { [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} with context properties: {BEFORE_ACTION=[compute_plan]} [junit4] 2> 688037 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed plan empty, remained 0 requested ops to try. [junit4] 2> 688037 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 105353927 sessionWrapper.createTime 105353840102387, this.sessionWrapper.createTime 105353840102387 [junit4] 2> 688037 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353929467337, stage=AFTER_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={properties.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard2"}, { [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688038 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353942480037, stage=BEFORE_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={properties.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard2"}, { [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688038 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: { [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} with context properties: {AFTER_ACTION=[compute_plan], unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard2"}, { [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard1"}]}}], BEFORE_ACTION=[compute_plan, execute_plan]} [junit4] 2> 688038 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ExecutePlanAction No operations to execute for event: { [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} [junit4] 2> 688038 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353979164187, stage=AFTER_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={properties.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard2"}, { [junit4] 2> "first":"testMergeIntegration_collection", [junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688039 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105353997412387, stage=SUCCEEDED, actionName='null', event={ [junit4] 2> "id":"5fcf907da94dTex1w6m50k5zvt1avp12djw8zm", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105345087023437, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{"testMergeIntegration_collection":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":7,\n \"SEARCHER.searcher.deletedDocs\":5,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":2,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":2,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testMergeIntegration_collection\"}}", [junit4] 2> "{\"core_node3\":{\n \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":3,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":3,\n \"violationType\":\"belowDocs\",\n \"node_name\":\"127.0.0.1:10000_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":3,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testMergeIntegration_collection\"}}"]}, [junit4] 2> "_enqueue_time_":105353615252837, [junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688040 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: index_size_trigger after 100ms [junit4] 2> 688040 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms [junit4] 2> 688040 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms [junit4] 2> 688040 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 332 ms for event id=5fcf907da94dTex1w6m50k5zvt1avp12djw8zm [junit4] 2> 688044 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[D9EB6F4461EDE612]) [ ] o.a.s.c.a.IndexSizeTriggerTest ####################################### [junit4] 2> ############ CLUSTER STATE ############ [junit4] 2> ####################################### [junit4] 2> ## Live nodes: 2 [junit4] 2> ## Empty nodes: 0 [junit4] 2> ## Dead nodes: 0 [junit4] 2> ## Collections: [testMergeIntegration_collection] [junit4] 2> DocCollection(testMergeIntegration_collection//clusterstate.json/19)={ [junit4] 2> "replicationFactor":"2", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"2", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"2", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{ [junit4] 2> "shard2":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node3":{ [junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n3", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":3, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":3}, [junit4] 2> "core_node4":{ [junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n4", [junit4] 2> "SEARCHER.searcher.maxDoc":3, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":3}}, [junit4] 2> "range":"0-7fffffff", [junit4] 2> "state":"active"}, [junit4] 2> "shard1":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node1":{ [junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":7, [junit4] 2> "SEARCHER.searcher.deletedDocs":5, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":2}, [junit4] 2> "core_node2":{ [junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n2", [junit4] 2> "SEARCHER.searcher.maxDoc":7, [junit4] 2> "SEARCHER.searcher.deletedDocs":5, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":2}}, [junit4] 2> "range":"80000000-ffffffff", [junit4] 2> "state":"active"}}} [junit4] 2> ## Max replicas per node: 2 [junit4] 2> ## Min replicas per node: 2 [junit4] 2> ## Total replicas: 4 [junit4] 2> ## * testMergeIntegration_collection 4 [junit4] 2> ## - active 4 [junit4] 2> ######### Solr op counts ########## [junit4] 2> ## - CREATE 1 [junit4] 2> ## - autoscaling 3 [junit4] 2> ## - update 19 [junit4] 2> ######### Autoscaling event counts ########### [junit4] 2> ## * Trigger: index_size_trigger [junit4] 2> ## - STARTED 1 [junit4] 2> ## - SUCCEEDED 1 [junit4] 2> [junit4] 2> 688045 DEBUG (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[D9EB6F4461EDE612]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 688045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 688045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 688045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 688045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 688145 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[D9EB6F4461EDE612]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMergeIntegration [junit4] 2> 688167 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[D9EB6F4461EDE612]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTrigger [junit4] 2> 688191 DEBUG (simCloudManagerPool-3108-thread-36) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testTrigger_collection / shard1: {"core_node1":{ [junit4] 2> "core":"testTrigger_collection_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testTrigger_collection"}} [junit4] 2> 688330 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[D9EB6F4461EDE612]) [ ] o.a.s.c.a.IndexSizeTriggerTest ####################################### [junit4] 2> ############ CLUSTER STATE ############ [junit4] 2> ####################################### [junit4] 2> ## Live nodes: 2 [junit4] 2> ## Empty nodes: 0 [junit4] 2> ## Dead nodes: 0 [junit4] 2> ## Collections: [testTrigger_collection] [junit4] 2> DocCollection(testTrigger_collection//clusterstate.json/48)={ [junit4] 2> "replicationFactor":"2", [junit4] 2> "pullReplicas":"0", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"2", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"2", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "autoCreated":"true", [junit4] 2> "shards":{ [junit4] 2> "shard2":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node3":{ [junit4] 2> "core":"testTrigger_collection_shard2_replica_n3", [junit4] 2> "SEARCHER.searcher.maxDoc":11, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":11}, [junit4] 2> "core_node4":{ [junit4] 2> "core":"testTrigger_collection_shard2_replica_n4", [junit4] 2> "SEARCHER.searcher.maxDoc":11, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":11}}, [junit4] 2> "range":"0-7fffffff", [junit4] 2> "state":"active"}, [junit4] 2> "shard1":{ [junit4] 2> "replicas":{ [junit4] 2> "core_node1":{ [junit4] 2> "core":"testTrigger_collection_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":14, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":14}, [junit4] 2> "core_node2":{ [junit4] 2> "core":"testTrigger_collection_shard1_replica_n2", [junit4] 2> "SEARCHER.searcher.maxDoc":14, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10000_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":14}}, [junit4] 2> "range":"80000000-ffffffff", [junit4] 2> "state":"active"}}} [junit4] 2> ## Max replicas per node: 2 [junit4] 2> ## Min replicas per node: 2 [junit4] 2> ## Total replicas: 4 [junit4] 2> ## * testTrigger_collection 4 [junit4] 2> ## - active 4 [junit4] 2> ######### Solr op counts ########## [junit4] 2> ## - CREATE 1 [junit4] 2> ## - update 26 [junit4] 2> ######### Autoscaling event counts ########### [junit4] 2> ## * Trigger: index_size_trigger [junit4] 2> ## - STARTED 1 [junit4] 2> ## - SUCCEEDED 1 [junit4] 2> [junit4] 2> 688330 DEBUG (TEST-IndexSizeTriggerTest.testTrigger-seed#[D9EB6F4461EDE612]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 688331 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 688331 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 688331 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 688331 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 688431 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[D9EB6F4461EDE612]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTrigger [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testTrigger -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 0.29s J0 | IndexSizeTriggerTest.testTrigger <<< [junit4] > Throwable #1: java.lang.AssertionError: number of ops expected:<2> but was:<1> [junit4] > at __randomizedtesting.SeedInfo.seed([D9EB6F4461EDE612:BA2059C6F822953F]:0) [junit4] > at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testTrigger(IndexSizeTriggerTest.java:187) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 688465 INFO (TEST-IndexSizeTriggerTest.testSplitIntegration-seed#[D9EB6F4461EDE612]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSplitIntegration [junit4] 2> 688499 DEBUG (simCloudManagerPool-3108-thread-69) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard1: {"core_node1":{ [junit4] 2> "core":"testSplitIntegration_collection_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":1, [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "SEARCHER.searcher.numDocs":0, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testSplitIntegration_collection"}} [junit4] 2> 688520 DEBUG (simCloudManagerPool-3108-thread-70) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 688520 DEBUG (simCloudManagerPool-3108-thread-70) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 688520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 688521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 688521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 688521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 688521 DEBUG (simCloudManagerPool-3108-thread-71) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 688521 DEBUG (simCloudManagerPool-3108-thread-71) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 688523 DEBUG (simCloudManagerPool-3108-thread-72) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 688523 DEBUG (simCloudManagerPool-3108-thread-72) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 688524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 688524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 688524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 688524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 688532 DEBUG (ScheduledTrigger-3100-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 688590 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"5fd7407fa7e5Tex1w6m50k5zvt1avp12djw8zq", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105378104715237, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}"]}, [junit4] 2> "belowSize":{}, [junit4] 2> "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} [junit4] 2> 688590 DEBUG (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger] [junit4] 2> 688591 INFO (ScheduledTrigger-3109-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105381601114687, stage=STARTED, actionName='null', event={ [junit4] 2> "id":"5fd7407fa7e5Tex1w6m50k5zvt1avp12djw8zq", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105378104715237, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}"]}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":105381593036537, [junit4] 2> "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener", [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"]}, message='null'} [junit4] 2> 688592 DEBUG (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"5fd7407fa7e5Tex1w6m50k5zvt1avp12djw8zq", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105378104715237, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}"]}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":105381593036537, [junit4] 2> "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} [junit4] 2> 688592 INFO (AutoscalingActionExecutor-3110-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=105381679647437, stage=BEFORE_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"5fd7407fa7e5Tex1w6m50k5zvt1avp12djw8zq", [junit4] 2> "source":"index_size_trigger", [junit4] 2> "eventTime":105378104715237, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\ [...truncated too long message...] settings :: file = /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/lucene/top-level-ivy-settings.xml resolve: jar-checksums: [mkdir] Created dir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/null1389867089 [copy] Copying 246 files to /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/null1389867089 [delete] Deleting directory /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/null1389867089 check-working-copy: [ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working [ivy:cachepath] confs: [default] [ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public [ivy:cachepath] found com.jcraft#jsch;0.1.53 in public [ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public [ivy:cachepath] found org.apache.httpcomponents#httpclient;4.3.6 in public [ivy:cachepath] found org.apache.httpcomponents#httpcore;4.3.3 in public [ivy:cachepath] found commons-logging#commons-logging;1.1.3 in public [ivy:cachepath] found commons-codec#commons-codec;1.6 in public [ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public [ivy:cachepath] :: resolution report :: resolve 30ms :: artifacts dl 2ms --------------------------------------------------------------------- | | modules || artifacts | | conf | number| search|dwnlded|evicted|| number|dwnlded| --------------------------------------------------------------------- | default | 8 | 0 | 0 | 0 || 8 | 0 | --------------------------------------------------------------------- [wc-checker] Initializing working copy... [wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". [wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation [wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. [wc-checker] Checking working copy status... -jenkins-base: BUILD SUCCESSFUL Total time: 97 minutes 53 seconds Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 [Lucene-Solr-7.x-Solaris] $ /bin/sh -xe /var/tmp/jenkins8506849149899308036.sh + mv lucene/build lucene/build.orig + mv solr/build solr/build.orig + ANT_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 + export ANT_HOME + PATH=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/bin:/export/home/jenkins/tools/java/64bit/jdk1.8.0/bin:/usr/bin:/usr/sbin + export PATH + python3.4 -u dev-tools/scripts/reproduceJenkinsFailures.py --no-git https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/consoleText [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/consoleText [repro] Revision: 8b29e5eef40e4877cefd2da957365ea310877c6e [repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testTrigger -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testSplitIntegration -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Encountered IncompleteRead exception, pausing and then retrying... [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/consoleText [repro] Revision: 8b29e5eef40e4877cefd2da957365ea310877c6e [repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testTrigger -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testSplitIntegration -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Encountered IncompleteRead exception, pausing and then retrying... [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/consoleText [repro] Revision: 8b29e5eef40e4877cefd2da957365ea310877c6e [repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testTrigger -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testSplitIntegration -Dtests.seed=D9EB6F4461EDE612 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=PLT -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] Encountered IncompleteRead exception, aborting after too many retries. Traceback (most recent call last): File "/usr/lib/python3.4/http/client.py", line 614, in _readinto_chunked chunk_left = self._read_next_chunk_size() File "/usr/lib/python3.4/http/client.py", line 559, in _read_next_chunk_size return int(line, 16) ValueError: invalid literal for int() with base 16: b'' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "dev-tools/scripts/reproduceJenkinsFailures.py", line 110, in fetchAndParseJenkinsLog for rawLine in consoleText: File "/usr/lib/python3.4/http/client.py", line 500, in read return super(HTTPResponse, self).read(amt) File "/usr/lib/python3.4/http/client.py", line 529, in readinto return self._readinto_chunked(b) File "/usr/lib/python3.4/http/client.py", line 618, in _readinto_chunked raise IncompleteRead(bytes(b[0:total_bytes])) http.client.IncompleteRead: IncompleteRead(0 bytes read) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3.4/http/client.py", line 614, in _readinto_chunked chunk_left = self._read_next_chunk_size() File "/usr/lib/python3.4/http/client.py", line 559, in _read_next_chunk_size return int(line, 16) ValueError: invalid literal for int() with base 16: b'' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "dev-tools/scripts/reproduceJenkinsFailures.py", line 110, in fetchAndParseJenkinsLog for rawLine in consoleText: File "/usr/lib/python3.4/http/client.py", line 500, in read return super(HTTPResponse, self).read(amt) File "/usr/lib/python3.4/http/client.py", line 529, in readinto return self._readinto_chunked(b) File "/usr/lib/python3.4/http/client.py", line 618, in _readinto_chunked raise IncompleteRead(bytes(b[0:total_bytes])) http.client.IncompleteRead: IncompleteRead(0 bytes read) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/python3.4/http/client.py", line 614, in _readinto_chunked chunk_left = self._read_next_chunk_size() File "/usr/lib/python3.4/http/client.py", line 559, in _read_next_chunk_size return int(line, 16) ValueError: invalid literal for int() with base 16: b'' During handling of the above exception, another exception occurred: Traceback (most recent call last): File "dev-tools/scripts/reproduceJenkinsFailures.py", line 110, in fetchAndParseJenkinsLog for rawLine in consoleText: File "/usr/lib/python3.4/http/client.py", line 500, in read return super(HTTPResponse, self).read(amt) File "/usr/lib/python3.4/http/client.py", line 529, in readinto return self._readinto_chunked(b) File "/usr/lib/python3.4/http/client.py", line 618, in _readinto_chunked raise IncompleteRead(bytes(b[0:total_bytes])) http.client.IncompleteRead: IncompleteRead(0 bytes read) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "dev-tools/scripts/reproduceJenkinsFailures.py", line 286, in <module> main() File "dev-tools/scripts/reproduceJenkinsFailures.py", line 236, in main tests = fetchAndParseJenkinsLog(config.url, numRetries = 2) File "dev-tools/scripts/reproduceJenkinsFailures.py", line 136, in fetchAndParseJenkinsLog return fetchAndParseJenkinsLog(url, numRetries - 1) File "dev-tools/scripts/reproduceJenkinsFailures.py", line 136, in fetchAndParseJenkinsLog return fetchAndParseJenkinsLog(url, numRetries - 1) File "dev-tools/scripts/reproduceJenkinsFailures.py", line 139, in fetchAndParseJenkinsLog raise RuntimeError('ERROR: fetching %s : %s' % (url, e)) RuntimeError: ERROR: fetching https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/580/consoleText : IncompleteRead(0 bytes read) Build step 'Execute shell' marked build as failure Archiving artifacts Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 [WARNINGS] Skipping publisher since build result is FAILURE Recording test results Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Email was triggered for: Failure - Any Sending email for trigger: Failure - Any Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2 Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org