Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/3144/ Java: 64bit/jdk-10.0.1 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed. FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration Error Message: did not finish processing in time Stack Trace: java.lang.AssertionError: did not finish processing in time at __randomizedtesting.SeedInfo.seed([172C8EF1AF7DBCB1:2EA237B18082754F]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:320) 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:1742) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985) 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:944) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:830) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:891) 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 13386 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest [junit4] 2> 660208 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_172C8EF1AF7DBCB1-001/init-core-data-001 [junit4] 2> 660209 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 660210 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) [junit4] 2> 660217 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_172C8EF1AF7DBCB1-001/tempDir-001 [junit4] 2> 660217 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 660218 INFO (Thread-1094) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 660218 INFO (Thread-1094) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 660219 ERROR (Thread-1094) [ ] 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> 660318 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:42713 [junit4] 2> 660319 INFO (zkConnectionManagerCallback-1536-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660321 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10 [junit4] 2> 660321 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 10.0.1+10 [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4b6757b7{/solr,null,AVAILABLE} [junit4] 2> 660322 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@20938a4{/solr,null,AVAILABLE} [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5d70d5c{SSL,[ssl, http/1.1]}{127.0.0.1:۴۴۹۲۹} [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.e.j.s.Server Started @۶۶۰۳۴۹ms [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@78561904{SSL,[ssl, http/1.1]}{127.0.0.1:۴۲۱۳۷} [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.e.j.s.Server Started @۶۶۰۳۵۰ms [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44929} [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42137} [junit4] 2> 660324 ERROR (jetty-launcher-1533-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 660324 ERROR (jetty-launcher-1533-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.7.0 [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.7.0 [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-11-25T21:25:01.181956Z [junit4] 2> 660324 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-11-25T21:25:01.181941Z [junit4] 2> 660326 INFO (zkConnectionManagerCallback-1540-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660326 INFO (zkConnectionManagerCallback-1539-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660326 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 660326 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 660329 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1001a8d3f640002, likely client has closed socket [junit4] 2> 660444 INFO (jetty-launcher-1533-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42713/solr [junit4] 2> 660445 INFO (zkConnectionManagerCallback-1544-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660446 INFO (zkConnectionManagerCallback-1546-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660486 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44929_solr [junit4] 2> 660486 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.c.Overseer Overseer (id=72086787994157060-127.0.0.1:44929_solr-n_0000000000) starting [junit4] 2> 660489 INFO (zkConnectionManagerCallback-1553-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660490 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42713/solr ready [junit4] 2> 660490 INFO (OverseerStateUpdate-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [n:127.0.0.1:44929_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:44929_solr [junit4] 2> 660495 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44929_solr [junit4] 2> 660495 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 660495 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 660496 INFO (zkCallback-1552-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 660496 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 660496 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 660496 INFO (zkCallback-1545-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 660497 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:44929_solr] [junit4] 2> 660498 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660498 DEBUG (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 660498 DEBUG (ScheduledTrigger-3157-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 [junit4] 2> 660508 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 660522 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44929.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660530 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44929.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660530 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44929.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660531 INFO (jetty-launcher-1533-thread-1) [n:127.0.0.1:44929_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_172C8EF1AF7DBCB1-001/tempDir-001/node1/. [junit4] 2> 660544 INFO (jetty-launcher-1533-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42713/solr [junit4] 2> 660545 INFO (zkConnectionManagerCallback-1558-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660547 INFO (zkConnectionManagerCallback-1560-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660549 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 660551 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 660551 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42137_solr [junit4] 2> 660552 INFO (zkCallback-1552-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 660552 INFO (zkCallback-1545-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 660559 INFO (zkCallback-1559-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 660570 INFO (zkConnectionManagerCallback-1567-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660571 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 660571 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42713/solr ready [junit4] 2> 660571 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 660583 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42137.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660590 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42137.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660591 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42137.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@58232c77 [junit4] 2> 660592 INFO (jetty-launcher-1533-thread-2) [n:127.0.0.1:42137_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_172C8EF1AF7DBCB1-001/tempDir-001/node2/. [junit4] 2> 660610 INFO (zkConnectionManagerCallback-1570-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660612 INFO (zkConnectionManagerCallback-1575-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 660613 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 660613 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42713/solr ready [junit4] 2> 660625 DEBUG (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10005_solr [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0 [junit4] 2> 660625 DEBUG (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0 [junit4] 2> 660625 DEBUG (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0 [junit4] 2> 660625 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1 [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0 [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr] [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660625 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0 [junit4] 2> 660625 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660646 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660666 DEBUG (ScheduledTrigger-3173-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660686 DEBUG (ScheduledTrigger-3173-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660706 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660726 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660747 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660767 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660787 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660807 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660828 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660839 INFO (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[172C8EF1AF7DBCB1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMixedBounds [junit4] 2> 660839 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testMixedBounds_collection, currentVersion=1 [junit4] 2> 660839 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=1 [junit4] 2> 660839 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1 [junit4] 2> 660849 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660849 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=2 [junit4] 2> 660849 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2 [junit4] 2> 660852 DEBUG (simCloudManagerPool-3172-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testMixedBounds_collection, currentVersion=3 [junit4] 2> 660861 DEBUG (simCloudManagerPool-3172-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=3 [junit4] 2> 660861 DEBUG (simCloudManagerPool-3172-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3 [junit4] 2> 660861 DEBUG (simCloudManagerPool-3172-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard1 (currentVersion=4): {"core_node1":{ [junit4] 2> "core":"testMixedBounds_collection_shard1_replica_n1", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":10240, [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6, [junit4] 2> "SEARCHER.searcher.numDocs":0}} [junit4] 2> 660869 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660871 DEBUG (simCloudManagerPool-3172-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=4 [junit4] 2> 660871 DEBUG (simCloudManagerPool-3172-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4 [junit4] 2> 660882 DEBUG (simCloudManagerPool-3172-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=5 [junit4] 2> 660882 DEBUG (simCloudManagerPool-3172-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5 [junit4] 2> 660882 DEBUG (simCloudManagerPool-3172-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard2 (currentVersion=6): {"core_node3":{ [junit4] 2> "core":"testMixedBounds_collection_shard2_replica_n3", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":10240, [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6, [junit4] 2> "SEARCHER.searcher.numDocs":0}} [junit4] 2> 660889 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660892 DEBUG (simCloudManagerPool-3172-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=6 [junit4] 2> 660893 DEBUG (simCloudManagerPool-3172-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6 [junit4] 2> 660893 DEBUG (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[172C8EF1AF7DBCB1]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=7 [junit4] 2> 660893 DEBUG (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[172C8EF1AF7DBCB1]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7 [junit4] 2> 660909 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660915 DEBUG (simCloudManagerPool-3172-thread-20) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 660915 DEBUG (simCloudManagerPool-3172-thread-20) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 660916 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 660916 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660916 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 660917 DEBUG (simCloudManagerPool-3172-thread-21) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 660917 DEBUG (simCloudManagerPool-3172-thread-21) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 660917 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 660918 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660918 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 660918 DEBUG (simCloudManagerPool-3172-thread-22) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 660918 DEBUG (simCloudManagerPool-3172-thread-22) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 660918 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 660919 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660919 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 660921 DEBUG (simCloudManagerPool-3172-thread-23) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 660921 DEBUG (simCloudManagerPool-3172-thread-23) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 660921 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 660922 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 660922 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 660929 DEBUG (ScheduledTrigger-3173-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660949 DEBUG (ScheduledTrigger-3173-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660969 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 660990 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 661010 DEBUG (ScheduledTrigger-3173-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 661030 DEBUG (ScheduledTrigger-3173-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 661030 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}} [junit4] 2> 661031 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger4, .auto_add_replicas, .scheduled_maintenance] [junit4] 2> 661032 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection .system, currentVersion=8 [junit4] 2> 661032 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=8 [junit4] 2> 661032 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8 [junit4] 2> 661042 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=9 [junit4] 2> 661043 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9 [junit4] 2> 661054 DEBUG (simCloudManagerPool-3172-thread-25) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=10 [junit4] 2> 661054 DEBUG (simCloudManagerPool-3172-thread-25) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10 [junit4] 2> 661054 DEBUG (simCloudManagerPool-3172-thread-27) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1 (currentVersion=11): {"core_node1":{ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":0, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":10240, [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6, [junit4] 2> "SEARCHER.searcher.numDocs":0}} [junit4] 2> 661064 DEBUG (simCloudManagerPool-3172-thread-26) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11 [junit4] 2> 661064 DEBUG (simCloudManagerPool-3172-thread-26) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11 [junit4] 2> 661064 DEBUG (simCloudManagerPool-3172-thread-24) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection .system, currentVersion=12 [junit4] 2> 661066 INFO (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445614117827472, stage=STARTED, actionName='null', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661067 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}} [junit4] 2> 661067 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445614168989222, stage=BEFORE_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger4}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661068 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: { [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}} with context properties: {BEFORE_ACTION=[compute_plan]} [junit4] 2> 661068 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testMixedBounds_collection&shard=shard2&splitMethod=rewrite [junit4] 2> 661068 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testMixedBounds_collection&shard=shard1&splitMethod=rewrite [junit4] 2> 661068 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445614244411672, stage=AFTER_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":2, [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={properties.operations=[{ [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard2", [junit4] 2> "params.splitMethod":"rewrite"}, { [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard1", [junit4] 2> "params.splitMethod":"rewrite"}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger4, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661069 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445614255298372, stage=BEFORE_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":2, [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={properties.operations=[{ [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard2", [junit4] 2> "params.splitMethod":"rewrite"}, { [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard1", [junit4] 2> "params.splitMethod":"rewrite"}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger4, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661069 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: { [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":2, [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}} with context properties: {operations=[{ [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard2", [junit4] 2> "params.splitMethod":"rewrite"}, { [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard1", [junit4] 2> "params.splitMethod":"rewrite"}], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]} [junit4] 2> 661069 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testMixedBounds_collection&shard=shard2&splitMethod=rewrite [junit4] 2> 661169 INFO (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.c.SplitShardCmd numSubShards set at: 2 [junit4] 2> 661211 DEBUG (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=12 [junit4] 2> 661211 DEBUG (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12 [junit4] 2> 661212 DEBUG (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.s.SimClusterStateProvider ** no leader in testMixedBounds_collection / shard2_0:{ [junit4] 2> "parent":"shard2", [junit4] 2> "stateTimestamp":"1543181255987054250", [junit4] 2> "range":"0-3fffffff", [junit4] 2> "state":"construction", [junit4] 2> "replicas":{ [junit4] 2> "core_node10":{ [junit4] 2> "core":"testMixedBounds_collection_shard2_0_replica_n9", [junit4] 2> "SEARCHER.searcher.maxDoc":253, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":146980, [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "base_url":"http://127.0.0.1:10006/solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "INDEX.sizeInGB":1.3688579201698303E-4, [junit4] 2> "SEARCHER.searcher.numDocs":253}, [junit4] 2> "core_node8":{ [junit4] 2> "core":"testMixedBounds_collection_shard2_0_replica_n7", [junit4] 2> "SEARCHER.searcher.maxDoc":253, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":146980, [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "base_url":"http://127.0.0.1:10005/solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "INDEX.sizeInGB":1.3688579201698303E-4, [junit4] 2> "SEARCHER.searcher.numDocs":253}}} [junit4] 2> 661213 DEBUG (simCloudManagerPool-3172-thread-30) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard2_0 (currentVersion=13): {"core_node10":{ [junit4] 2> "core":"testMixedBounds_collection_shard2_0_replica_n9", [junit4] 2> "shard":"shard2_0", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":253, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":146980, [junit4] 2> "base_url":"http://127.0.0.1:10006/solr", [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":1.3688579201698303E-4, [junit4] 2> "SEARCHER.searcher.numDocs":253}} [junit4] 2> 661212 DEBUG (simCloudManagerPool-3172-thread-29) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard2_1 (currentVersion=13): {"core_node12":{ [junit4] 2> "core":"testMixedBounds_collection_shard2_1_replica_n11", [junit4] 2> "shard":"shard2_1", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":252, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":136240, [junit4] 2> "base_url":"http://127.0.0.1:10006/solr", [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":1.268833875656128E-4, [junit4] 2> "SEARCHER.searcher.numDocs":252}} [junit4] 2> 661215 DEBUG (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=13 [junit4] 2> 661215 DEBUG (simCloudManagerPool-3172-thread-28) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13 [junit4] 2> 661216 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testMixedBounds_collection&shard=shard1&splitMethod=rewrite [junit4] 2> 661216 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=14 [junit4] 2> 661216 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14 [junit4] 2> 661317 INFO (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.c.SplitShardCmd numSubShards set at: 2 [junit4] 2> 661359 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=15 [junit4] 2> 661359 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 15 [junit4] 2> 661360 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** no leader in testMixedBounds_collection / shard1_0:{ [junit4] 2> "parent":"shard1", [junit4] 2> "stateTimestamp":"1543181263365147600", [junit4] 2> "range":"80000000-bfffffff", [junit4] 2> "state":"construction", [junit4] 2> "replicas":{ [junit4] 2> "core_node18":{ [junit4] 2> "core":"testMixedBounds_collection_shard1_0_replica_n17", [junit4] 2> "SEARCHER.searcher.maxDoc":248, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":144480, [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "base_url":"http://127.0.0.1:10005/solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "INDEX.sizeInGB":1.3455748558044434E-4, [junit4] 2> "SEARCHER.searcher.numDocs":248}, [junit4] 2> "core_node20":{ [junit4] 2> "core":"testMixedBounds_collection_shard1_0_replica_n19", [junit4] 2> "SEARCHER.searcher.maxDoc":248, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":144480, [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "base_url":"http://127.0.0.1:10006/solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "INDEX.sizeInGB":1.3455748558044434E-4, [junit4] 2> "SEARCHER.searcher.numDocs":248}}} [junit4] 2> 661360 DEBUG (simCloudManagerPool-3172-thread-34) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard1_1 (currentVersion=16): {"core_node22":{ [junit4] 2> "core":"testMixedBounds_collection_shard1_1_replica_n21", [junit4] 2> "shard":"shard1_1", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10006_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":247, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":133740, [junit4] 2> "base_url":"http://127.0.0.1:10006/solr", [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":1.245550811290741E-4, [junit4] 2> "SEARCHER.searcher.numDocs":247}} [junit4] 2> 661360 DEBUG (simCloudManagerPool-3172-thread-35) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMixedBounds_collection / shard1_0 (currentVersion=16): {"core_node18":{ [junit4] 2> "core":"testMixedBounds_collection_shard1_0_replica_n17", [junit4] 2> "shard":"shard1_0", [junit4] 2> "collection":"testMixedBounds_collection", [junit4] 2> "node_name":"127.0.0.1:10005_solr", [junit4] 2> "type":"NRT", [junit4] 2> "leader":"true", [junit4] 2> "SEARCHER.searcher.maxDoc":248, [junit4] 2> "SEARCHER.searcher.deletedDocs":0, [junit4] 2> "INDEX.sizeInBytes":144480, [junit4] 2> "base_url":"http://127.0.0.1:10005/solr", [junit4] 2> "state":"active", [junit4] 2> "INDEX.sizeInGB":1.3455748558044434E-4, [junit4] 2> "SEARCHER.searcher.numDocs":248}} [junit4] 2> 661363 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=16 [junit4] 2> 661363 DEBUG (simCloudManagerPool-3172-thread-33) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 16 [junit4] 2> 661364 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445628993828872, stage=AFTER_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":2, [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={properties.operations=[{ [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.async":"index_size_trigger4/19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt/0", [junit4] 2> "params.waitForFinalState":"true", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard2", [junit4] 2> "params.splitMethod":"rewrite"}, { [junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard", [junit4] 2> "method":"GET", [junit4] 2> "params.action":"SPLITSHARD", [junit4] 2> "params.async":"index_size_trigger4/19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt/0", [junit4] 2> "params.waitForFinalState":"true", [junit4] 2> "params.collection":"testMixedBounds_collection", [junit4] 2> "params.shard":"shard1", [junit4] 2> "params.splitMethod":"rewrite"}], properties.BEFORE_ACTION=[compute_plan, execute_plan], properties.responses=[{status={state=completed,msg=found [index_size_trigger4/19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt/0] in completed tasks},success=}, {status={state=completed,msg=found [index_size_trigger4/19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt/0] in completed tasks},success=}], source=index_size_trigger4, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661365 DEBUG (simCloudManagerPool-3172-thread-38) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=17 [junit4] 2> 661365 DEBUG (simCloudManagerPool-3172-thread-38) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 17 [junit4] 2> 661365 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445629095213122, stage=SUCCEEDED, actionName='null', event={ [junit4] 2> "id":"19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445607022950722, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":2, [junit4] 2> "aboveSize":{ [junit4] 2> "testMixedBounds_collection_shard1_replica_n1":"docs=495, bytes=257740", [junit4] 2> "testMixedBounds_collection_shard2_replica_n3":"docs=505, bytes=262740"}, [junit4] 2> "belowSize":{}, [junit4] 2> "_enqueue_time_":445612359644272, [junit4] 2> "requestedOps":[ [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}, [junit4] 2> { [junit4] 2> "action":"SPLITSHARD", [junit4] 2> "hints":{ [junit4] 2> "COLL_SHARD":[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1"}], [junit4] 2> "PARAMS":{"splitMethod":"rewrite"}}}]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661366 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: index_size_trigger4 after 100ms [junit4] 2> 661366 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms [junit4] 2> 661366 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms [junit4] 2> 661366 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 14958 ms for event id=19546f84ff942Tc78ofvj0vm2fvztibxoah0lqt [junit4] 2> 661366 DEBUG (simCloudManagerPool-3172-thread-39) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 661367 DEBUG (simCloudManagerPool-3172-thread-39) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 661367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 661367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 661367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 661385 DEBUG (simCloudManagerPool-3172-thread-49) [ ] o.a.s.c.a.s.SimClusterStateProvider -- attempting to delete nonexistent doc id-8800-9 from core_node12:{"leader":"true","core":"testMixedBounds_collection_shard2_1_replica_n11","SEARCHER.searcher.maxDoc":252,"SEARCHER.searcher.deletedDocs":252,"INDEX.sizeInBytes":136240,"node_name":"127.0.0.1:10006_solr","base_url":"http://127.0.0.1:10006/solr","state":"active","type":"NRT","INDEX.sizeInGB":1.268833875656128E-4,"SEARCHER.searcher.numDocs":0} [junit4] 2> 661385 DEBUG (simCloudManagerPool-3172-thread-49) [ ] o.a.s.c.a.s.SimClusterStateProvider -- attempting to delete nonexistent doc id-9200-9 from core_node12:{"leader":"true","core":"testMixedBounds_collection_shard2_1_replica_n11","SEARCHER.searcher.maxDoc":252,"SEARCHER.searcher.deletedDocs":252,"INDEX.sizeInBytes":136240,"node_name":"127.0.0.1:10006_solr","base_url":"http://127.0.0.1:10006/solr","state":"active","type":"NRT","INDEX.sizeInGB":1.268833875656128E-4,"SEARCHER.searcher.numDocs":0} [junit4] 2> 661385 DEBUG (simCloudManagerPool-3172-thread-49) [ ] o.a.s.c.a.s.SimClusterStateProvider -- attempting to delete nonexistent doc id-9400-9 from core_node12:{"leader":"true","core":"testMixedBounds_collection_shard2_1_replica_n11","SEARCHER.searcher.maxDoc":252,"SEARCHER.searcher.deletedDocs":252,"INDEX.sizeInBytes":136240,"node_name":"127.0.0.1:10006_solr","base_url":"http://127.0.0.1:10006/solr","state":"active","type":"NRT","INDEX.sizeInGB":1.268833875656128E-4,"SEARCHER.searcher.numDocs":0} [junit4] 2> 661385 DEBUG (simCloudManagerPool-3172-thread-49) [ ] o.a.s.c.a.s.SimClusterStateProvider -- attempting to delete nonexistent doc id-9600-9 from core_node12:{"leader":"true","core":"testMixedBounds_collection_shard2_1_replica_n11","SEARCHER.searcher.maxDoc":252,"SEARCHER.searcher.deletedDocs":252,"INDEX.sizeInBytes":136240,"node_name":"127.0.0.1:10006_solr","base_url":"http://127.0.0.1:10006/solr","state":"active","type":"NRT","INDEX.sizeInGB":1.268833875656128E-4,"SEARCHER.searcher.numDocs":0} [junit4] 2> 661385 DEBUG (simCloudManagerPool-3172-thread-51) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 661386 DEBUG (simCloudManagerPool-3172-thread-51) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 661386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 661386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 661386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 661466 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 661486 DEBUG (ScheduledTrigger-3173-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 661490 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}} [junit4] 2> 661490 DEBUG (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger4, .auto_add_replicas, .scheduled_maintenance] [junit4] 2> 661490 INFO (ScheduledTrigger-3173-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445635340463122, stage=STARTED, actionName='null', event={ [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}}, context={}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661491 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}} [junit4] 2> 661491 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445635358846872, stage=BEFORE_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger4}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661491 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: { [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}} with context properties: {BEFORE_ACTION=[compute_plan]} [junit4] 2> 661492 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed plan empty, remained 0 requested ops to try. [junit4] 2> 661492 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445635445224372, stage=AFTER_ACTION, actionName='compute_plan', event={ [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}}, context={properties.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger4, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661493 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445635456276222, stage=BEFORE_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}}, context={properties.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger4, properties.AFTER_ACTION=[compute_plan]}, config={ [junit4] 2> "trigger":"index_size_trigger4", [junit4] 2> "stage":[ [junit4] 2> "STARTED", [junit4] 2> "ABORTED", [junit4] 2> "SUCCEEDED", [junit4] 2> "FAILED"], [junit4] 2> "beforeAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "afterAction":[ [junit4] 2> "compute_plan", [junit4] 2> "execute_plan"], [junit4] 2> "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener"}, message='null'} [junit4] 2> 661493 DEBUG (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: { [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}} with context properties: {AFTER_ACTION=[compute_plan], unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{ [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}], BEFORE_ACTION=[compute_plan, execute_plan]} [junit4] 2> 661493 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.ExecutePlanAction No operations to execute for event: { [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard1_1"}]}}]}} [junit4] 2> 661493 INFO (AutoscalingActionExecutor-3174-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=445635479773572, stage=AFTER_ACTION, actionName='execute_plan', event={ [junit4] 2> "id":"1954c59fe1854Tc78ofvj0vm2fvztibxoah0lqw", [junit4] 2> "source":"index_size_trigger4", [junit4] 2> "eventTime":445630136588372, [junit4] 2> "eventType":"INDEXSIZE", [junit4] 2> "properties":{ [junit4] 2> "__start__":1, [junit4] 2> "aboveSize":{}, [junit4] 2> "belowSize":{ [junit4] 2> ".system_shard1_replica_n1":"docs=2, bytes=11240", [junit4] 2> "testMixedBounds_collection_shard1_0_replica_n17":"docs=7, bytes=23980", [junit4] 2> "testMixedBounds_collection_shard1_1_replica_n21":"docs=5, bytes=12740", [junit4] 2> "testMixedBounds_collection_shard2_0_replica_n9":"docs=12, bytes=26480", [junit4] 2> "testMixedBounds_collection_shard2_1_replica_n11":"docs=0, bytes=10240"}, [junit4] 2> "_enqueue_time_":445635312282972, [junit4] 2> "requestedOps":[{ [junit4] 2> "action":"MERGESHARDS", [junit4] 2> "hints":{"COLL_SHARD":[ [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "second":"shard2_1"}, [junit4] 2> { [junit4] 2> "first":"testMixedBounds_collection", [junit4] 2> "s [...truncated too long message...] 2> 664524 INFO (jetty-closer-1534-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 664524 INFO (zkCallback-1552-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 664525 INFO (zkCallback-1566-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 664525 INFO (jetty-closer-1534-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72086787994157060-127.0.0.1:44929_solr-n_0000000000) closing [junit4] 2> 664525 INFO (OverseerStateUpdate-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [n:127.0.0.1:44929_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44929_solr [junit4] 2> 664525 WARN (OverseerAutoScalingTriggerThread-72086787994157060-127.0.0.1:44929_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 664525 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 664525 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@589f2a9b: rootName = solr_42137, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@b3dafde [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor [junit4] 2> 664527 INFO (zkCallback-1545-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1) [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely [junit4] 2> 664527 DEBUG (jetty-closer-1534-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 664528 INFO (zkCallback-1559-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42137_solr [junit4] 2> 664530 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 664530 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@12936513: rootName = solr_42137, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6d8291dc [junit4] 2> 664530 INFO (jetty-closer-1534-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4b6757b7{/solr,null,UNAVAILABLE} [junit4] 2> 664530 INFO (jetty-closer-1534-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging [junit4] 2> 664531 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:42137_solr [junit4] 2> 664531 INFO (jetty-closer-1534-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 664531 INFO (zkCallback-1559-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 664531 INFO (zkCallback-1566-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0) [junit4] 2> 664532 INFO (jetty-closer-1534-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@20938a4{/solr,null,UNAVAILABLE} [junit4] 2> 664532 INFO (jetty-closer-1534-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging [junit4] 2> 664533 ERROR (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 664533 INFO (SUITE-IndexSizeTriggerTest-seed#[172C8EF1AF7DBCB1]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42713 42713 [junit4] 2> 664735 INFO (Thread-1094) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42713 42713 [junit4] 2> 664735 WARN (Thread-1094) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 5 /solr/aliases.json [junit4] 2> 2 /solr/security.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 5 /solr/clusterstate.json [junit4] 2> 5 /solr/clusterprops.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 5 /solr/live_nodes [junit4] 2> 5 /solr/collections [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_172C8EF1AF7DBCB1-001 [junit4] 2> Nov 25, 2018 9:25:05 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1129, maxMBSortInHeap=7.779508337166787, sim=RandomSimilarity(queryNorm=false): {}, locale=fa-IR, timezone=Asia/Novokuznetsk [junit4] 2> NOTE: Linux 4.15.0-39-generic amd64/Oracle Corporation 10.0.1 (64-bit)/cpus=8,threads=1,free=228386888,total=488112128 [junit4] 2> NOTE: All tests run in this JVM: [ConjunctionSolrSpellCheckerTest, TestPrepRecovery, InfixSuggestersTest, TestCoreAdminApis, TestReqParamsAPI, TestCSVLoader, TestSQLHandlerNonCloud, UUIDFieldTest, TestSolrCoreSnapshots, WordBreakSolrSpellCheckerTest, DisMaxRequestHandlerTest, TestDistributedSearch, ShowFileRequestHandlerTest, CdcrBidirectionalTest, TestConfigOverlay, TestFastOutputStream, HttpPartitionOnCommitTest, TestReloadDeadlock, CacheHeaderTest, TestClassicSimilarityFactory, AddSchemaFieldsUpdateProcessorFactoryTest, TestGeoJSONResponseWriter, HdfsTlogReplayBufferedWhileIndexingTest, TestLuceneIndexBackCompat, DistributedFacetPivotLongTailTest, TestRandomFaceting, TestCopyFieldCollectionResource, TestFieldCacheReopen, AutoAddReplicasPlanActionTest, TestNumericTokenStream, BasicFunctionalityTest, CloudMLTQParserTest, TestCursorMarkWithoutUniqueKey, ZkSolrClientTest, RegexBoostProcessorTest, CoreAdminOperationTest, ActionThrottleTest, TestOverriddenPrefixQueryForCustomFieldType, ReplicaListTransformerTest, TestDeleteCollectionOnDownNodes, UniqFieldsUpdateProcessorFactoryTest, TestFieldTypeResource, CurrencyRangeFacetCloudTest, SolrMetricReporterTest, TestRequestForwarding, TestFreeTextSuggestions, TestPhraseSuggestions, TestApiFramework, SpellPossibilityIteratorTest, TestManagedResourceStorage, TolerantUpdateProcessorTest, OutOfBoxZkACLAndCredentialsProvidersTest, TermVectorComponentTest, TestCloudJSONFacetSKG, ScheduledMaintenanceTriggerTest, ExitableDirectoryReaderTest, TestJsonFacetsStatsParsing, BufferStoreTest, NoCacheHeaderTest, FastVectorHighlighterTest, TestShardHandlerFactory, TestStressReorder, TestSchemaSimilarityResource, TlogReplayBufferedWhileIndexingTest, PrimUtilsTest, PluginInfoTest, MergeStrategyTest, TestSlowCompositeReaderWrapper, NotRequiredUniqueKeyTest, StressHdfsTest, HLLSerializationTest, MultiSolrCloudTestCaseTest, HdfsBasicDistributedZkTest, RankQueryTest, AutoscalingHistoryHandlerTest, SharedFSAutoReplicaFailoverTest, TestUniqueKeyFieldResource, TestScoreJoinQPNoScore, TestPseudoReturnFields, MBeansHandlerTest, TestIndexSearcher, TestExpandComponent, TestInPlaceUpdatesDistrib, SaslZkACLProviderTest, ProtectedTermFilterFactoryTest, TestDynamicLoading, CreateRoutedAliasTest, TestPointFields, TestNumericTerms32, PKIAuthenticationIntegrationTest, NodeAddedTriggerIntegrationTest, MetricUtilsTest, TaggerTest, TestSurroundQueryParser, AddBlockUpdateTest, TestFoldingMultitermQuery, TestRuleBasedAuthorizationPlugin, PrimitiveFieldTypeTest, TestCloudDeleteByQuery, TestSimPolicyCloud, IndexSizeTriggerTest] [junit4] Completed [247/836 (1!)] on J1 in 4.81s, 6 tests, 1 failure <<< FAILURES! [...truncated 44688 lines...] [repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/3144/consoleText [repro] Revision: bcb5e8cb62bf1471f92e40b46272d9b15fd8ec0c [repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" [repro] Repro line: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testSplitIntegration -Dtests.seed=172C8EF1AF7DBCB1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fa-IR -Dtests.timezone=Asia/Novokuznetsk -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [repro] ant clean [...truncated 6 lines...] [repro] Test suites by module: [repro] solr/core [repro] IndexSizeTriggerTest [repro] ant compile-test [...truncated 3591 lines...] [repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.IndexSizeTriggerTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=172C8EF1AF7DBCB1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fa-IR -Dtests.timezone=Asia/Novokuznetsk -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [...truncated 101 lines...] [repro] Failures: [repro] 0/5 failed: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest [repro] Exiting with code 0 [...truncated 40 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org