You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/03/26 19:19:26 UTC
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1762 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1762/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.DeleteReplicaTest.deleteReplicaOnIndexing
Error Message:
Time out waiting for LIR state get removed
Stack Trace:
java.util.concurrent.TimeoutException: Time out waiting for LIR state get removed
at __randomizedtesting.SeedInfo.seed([42FEA10594B25F6D:3B858D8A372F954E]:0)
at org.apache.solr.util.TimeOut.waitFor(TimeOut.java:66)
at org.apache.solr.cloud.DeleteReplicaTest.deleteReplicaOnIndexing(DeleteReplicaTest.java:331)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 1850 lines...]
[junit4] JVM J1: stdout was not empty, see: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/build/core/test/temp/junit4-J1-20180326_174037_6526275874094895741092.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] codec: FastDecompressionCompressingStoredFields, pf: TestBloomFilteredLucenePostings, dvf: Direct
[junit4] <<< JVM J1: EOF ----
[...truncated 10242 lines...]
[junit4] Suite: org.apache.solr.cloud.DeleteReplicaTest
[junit4] 2> 147651 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-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-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/init-core-data-001
[junit4] 2> 147652 WARN (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=27 numCloses=27
[junit4] 2> 147652 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 147654 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-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> 147654 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001
[junit4] 2> 147654 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 147654 INFO (Thread-115) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 147654 INFO (Thread-115) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 147656 ERROR (Thread-115) [ ] 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> 147755 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:47357
[junit4] 2> 147758 INFO (zkConnectionManagerCallback-165-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147763 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 147763 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 147764 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 147765 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 147765 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 147765 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 147765 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 147767 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 147767 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 147767 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 147767 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3bc12b59{/solr,null,AVAILABLE}
[junit4] 2> 147769 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 147769 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 147769 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 147770 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@47a577ab{/solr,null,AVAILABLE}
[junit4] 2> 147771 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 147771 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 147771 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 147771 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@483c6a23{/solr,null,AVAILABLE}
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6f7d8e70{HTTP/1.1,[http/1.1]}{127.0.0.1:50029}
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@127891dd{/solr,null,AVAILABLE}
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.e.j.s.Server Started @148079ms
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50029}
[junit4] 2> 147773 ERROR (jetty-launcher-162-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5b551a73{HTTP/1.1,[http/1.1]}{127.0.0.1:63812}
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-2) [ ] o.e.j.s.Server Started @148080ms
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63812}
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-26T18:00:16.794Z
[junit4] 2> 147773 ERROR (jetty-launcher-162-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147773 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-26T18:00:16.795Z
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7559e63{HTTP/1.1,[http/1.1]}{127.0.0.1:60830}
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-4) [ ] o.e.j.s.Server Started @148081ms
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=60830}
[junit4] 2> 147774 ERROR (jetty-launcher-162-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147774 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@22b80c46{HTTP/1.1,[http/1.1]}{127.0.0.1:35333}
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.e.j.s.Server Started @148081ms
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35333}
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-26T18:00:16.796Z
[junit4] 2> 147775 ERROR (jetty-launcher-162-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 147775 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-26T18:00:16.796Z
[junit4] 2> 147779 INFO (zkConnectionManagerCallback-167-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147779 INFO (zkConnectionManagerCallback-171-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147780 INFO (zkConnectionManagerCallback-169-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147780 INFO (zkConnectionManagerCallback-173-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147780 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 147780 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 147780 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 147780 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 147787 INFO (jetty-launcher-162-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47357/solr
[junit4] 2> 147795 INFO (zkConnectionManagerCallback-177-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147796 INFO (jetty-launcher-162-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47357/solr
[junit4] 2> 147798 INFO (jetty-launcher-162-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47357/solr
[junit4] 2> 147798 INFO (jetty-launcher-162-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47357/solr
[junit4] 2> 147801 INFO (zkConnectionManagerCallback-181-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147802 INFO (zkConnectionManagerCallback-187-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147802 INFO (zkConnectionManagerCallback-189-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147803 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 0x1003f7487270007, likely client has closed socket
[junit4] 2> 147805 INFO (zkConnectionManagerCallback-193-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147805 INFO (zkConnectionManagerCallback-191-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147806 INFO (zkConnectionManagerCallback-195-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147813 INFO (zkConnectionManagerCallback-197-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147865 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 147866 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:60830_solr
[junit4] 2> 147867 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.Overseer Overseer (id=72127363754164235-127.0.0.1:60830_solr-n_0000000000) starting
[junit4] 2> 147883 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 147885 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50029_solr
[junit4] 2> 147888 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 147888 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 147955 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 147956 INFO (zkConnectionManagerCallback-205-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 147959 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 147963 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35333_solr
[junit4] 2> 148013 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 148014 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 148023 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 148073 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 148076 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:47357/solr ready
[junit4] 2> 148083 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60830_solr
[junit4] 2> 148086 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 148086 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 148086 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 148088 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 148091 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 148131 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63812_solr
[junit4] 2> 148134 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 148135 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 148155 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 148199 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 148260 INFO (zkCallback-204-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4)
[junit4] 2> 148543 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50029.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148548 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50029.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148548 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50029.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148549 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node1/.
[junit4] 2> 148582 INFO (zkConnectionManagerCallback-209-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 148598 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60830.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148604 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60830.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148605 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60830.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148605 INFO (jetty-launcher-162-thread-4) [n:127.0.0.1:60830_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node3/.
[junit4] 2> 148644 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 148645 INFO (jetty-launcher-162-thread-1) [n:127.0.0.1:50029_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:47357/solr ready
[junit4] 2> 148863 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63812.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148868 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63812.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148868 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63812.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 148869 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node2/.
[junit4] 2> 148873 INFO (zkConnectionManagerCallback-213-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 148875 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 148876 INFO (jetty-launcher-162-thread-2) [n:127.0.0.1:63812_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:47357/solr ready
[junit4] 2> 150257 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35333.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 150262 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35333.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 150262 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35333.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 150263 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node4/.
[junit4] 2> 150268 INFO (zkConnectionManagerCallback-217-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 150271 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 150272 INFO (jetty-launcher-162-thread-3) [n:127.0.0.1:35333_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:47357/solr ready
[junit4] 2> 150301 INFO (zkConnectionManagerCallback-219-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 150305 INFO (zkConnectionManagerCallback-223-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 150307 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 150309 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:47357/solr ready
[junit4] 2> 150350 INFO (TEST-DeleteReplicaTest.deleteLiveReplicaTest-seed#[42FEA10594B25F6D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteLiveReplicaTest
[junit4] 2> 150352 INFO (qtp2113710410-918) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=delLiveColl&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 150356 INFO (OverseerThreadFactory-524-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection delLiveColl
[junit4] 2> 150471 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"delLiveColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"delLiveColl_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35333/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 150474 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"delLiveColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"delLiveColl_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50029/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 150477 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"delLiveColl",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"delLiveColl_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:63812/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 150480 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"delLiveColl",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"delLiveColl_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:60830/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 150684 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=delLiveColl_shard1_replica_n1&action=CREATE&numShards=2&collection=delLiveColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 150685 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 150687 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=delLiveColl_shard1_replica_n2&action=CREATE&numShards=2&collection=delLiveColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 150687 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 150688 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=delLiveColl_shard2_replica_n6&action=CREATE&numShards=2&collection=delLiveColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 150688 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 150691 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=delLiveColl_shard2_replica_n4&action=CREATE&numShards=2&collection=delLiveColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 150691 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 150808 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150808 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150808 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150808 INFO (zkCallback-196-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150808 INFO (zkCallback-194-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150809 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150809 INFO (zkCallback-192-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 150809 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151710 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 151714 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 151716 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 151723 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.s.IndexSchema [delLiveColl_shard1_replica_n1] Schema name=minimal
[junit4] 2> 151726 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 151726 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'delLiveColl_shard1_replica_n1' using configuration from collection delLiveColl, trusted=true
[junit4] 2> 151726 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35333.solr.core.delLiveColl.shard1.replica_n1' (registry 'solr.core.delLiveColl.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 151726 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 151726 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SolrCore [[delLiveColl_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node4/delLiveColl_shard1_replica_n1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node4/./delLiveColl_shard1_replica_n1/data/]
[junit4] 2> 151727 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.s.IndexSchema [delLiveColl_shard2_replica_n4] Schema name=minimal
[junit4] 2> 151729 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 151729 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'delLiveColl_shard2_replica_n4' using configuration from collection delLiveColl, trusted=true
[junit4] 2> 151729 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63812.solr.core.delLiveColl.shard2.replica_n4' (registry 'solr.core.delLiveColl.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 151729 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 151730 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SolrCore [[delLiveColl_shard2_replica_n4] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node2/delLiveColl_shard2_replica_n4], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node2/./delLiveColl_shard2_replica_n4/data/]
[junit4] 2> 151737 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 151744 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.s.IndexSchema [delLiveColl_shard2_replica_n6] Schema name=minimal
[junit4] 2> 151746 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.s.IndexSchema [delLiveColl_shard1_replica_n2] Schema name=minimal
[junit4] 2> 151747 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 151747 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'delLiveColl_shard1_replica_n2' using configuration from collection delLiveColl, trusted=true
[junit4] 2> 151748 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50029.solr.core.delLiveColl.shard1.replica_n2' (registry 'solr.core.delLiveColl.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 151748 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 151748 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.SolrCore [[delLiveColl_shard1_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node1/delLiveColl_shard1_replica_n2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node1/./delLiveColl_shard1_replica_n2/data/]
[junit4] 2> 151756 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 151756 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'delLiveColl_shard2_replica_n6' using configuration from collection delLiveColl, trusted=true
[junit4] 2> 151757 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_60830.solr.core.delLiveColl.shard2.replica_n6' (registry 'solr.core.delLiveColl.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 151757 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 151757 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.SolrCore [[delLiveColl_shard2_replica_n6] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node3/delLiveColl_shard2_replica_n6], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node3/./delLiveColl_shard2_replica_n6/data/]
[junit4] 2> 151794 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 151794 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 151795 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 151795 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 151798 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@60ec5285[delLiveColl_shard1_replica_n1] main]
[junit4] 2> 151799 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 151800 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 151800 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 151800 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596024129659600896
[junit4] 2> 151802 INFO (searcherExecutor-533-thread-1-processing-n:127.0.0.1:35333_solr x:delLiveColl_shard1_replica_n1 c:delLiveColl s:shard1 r:core_node3) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SolrCore [delLiveColl_shard1_replica_n1] Registered new searcher Searcher@60ec5285[delLiveColl_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 151804 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 151804 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 151805 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 151805 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 151806 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/delLiveColl/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 151807 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@40cc7731[delLiveColl_shard1_replica_n2] main]
[junit4] 2> 151808 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 151808 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 151809 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 151809 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596024129669038080
[junit4] 2> 151812 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 151812 INFO (searcherExecutor-535-thread-1-processing-n:127.0.0.1:50029_solr x:delLiveColl_shard1_replica_n2 c:delLiveColl s:shard1 r:core_node5) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.SolrCore [delLiveColl_shard1_replica_n2] Registered new searcher Searcher@40cc7731[delLiveColl_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 151816 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/delLiveColl/terms/shard1 to Terms{values={core_node3=0, core_node5=0}, version=1}
[junit4] 2> 151828 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 151828 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 151829 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 151829 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 151830 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 151830 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 151830 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@7285e755[delLiveColl_shard2_replica_n4] main]
[junit4] 2> 151830 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 151830 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 151833 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 151833 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@56ace959[delLiveColl_shard2_replica_n6] main]
[junit4] 2> 151834 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 151834 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 151834 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596024129695252480
[junit4] 2> 151835 INFO (searcherExecutor-534-thread-1-processing-n:127.0.0.1:63812_solr x:delLiveColl_shard2_replica_n4 c:delLiveColl s:shard2 r:core_node7) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SolrCore [delLiveColl_shard2_replica_n4] Registered new searcher Searcher@7285e755[delLiveColl_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 151835 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 151836 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 151836 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 151837 INFO (searcherExecutor-536-thread-1-processing-n:127.0.0.1:60830_solr x:delLiveColl_shard2_replica_n6 c:delLiveColl s:shard2 r:core_node8) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.SolrCore [delLiveColl_shard2_replica_n6] Registered new searcher Searcher@56ace959[delLiveColl_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 151837 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1596024129698398208
[junit4] 2> 151839 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ZkShardTerms Successful update of terms at /collections/delLiveColl/terms/shard2 to Terms{values={core_node7=0}, version=0}
[junit4] 2> 151844 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.ZkShardTerms Successful update of terms at /collections/delLiveColl/terms/shard2 to Terms{values={core_node7=0, core_node8=0}, version=1}
[junit4] 2> 151846 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 151948 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151948 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151948 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151948 INFO (zkCallback-196-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151948 INFO (zkCallback-194-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151948 INFO (zkCallback-192-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151949 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 151949 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152313 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 152313 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 152313 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:35333/solr/delLiveColl_shard1_replica_n1/
[junit4] 2> 152313 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=delLiveColl_shard1_replica_n1 url=http://127.0.0.1:35333/solr START replicas=[http://127.0.0.1:50029/solr/delLiveColl_shard1_replica_n2/] nUpdates=100
[junit4] 2> 152317 INFO (qtp1804021990-901) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.c.S.Request [delLiveColl_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 152347 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 152347 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 152348 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:63812/solr/delLiveColl_shard2_replica_n4/
[junit4] 2> 152348 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=delLiveColl_shard2_replica_n4 url=http://127.0.0.1:63812/solr START replicas=[http://127.0.0.1:60830/solr/delLiveColl_shard2_replica_n6/] nUpdates=100
[junit4] 2> 152351 INFO (qtp884088892-927) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.S.Request [delLiveColl_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 152615 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=delLiveColl_shard1_replica_n1 url=http://127.0.0.1:35333/solr DONE. We have no versions. sync failed.
[junit4] 2> 152615 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 152615 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 152615 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 152619 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:35333/solr/delLiveColl_shard1_replica_n1/ shard1
[junit4] 2> 152648 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=delLiveColl_shard2_replica_n4 url=http://127.0.0.1:63812/solr DONE. We have no versions. sync failed.
[junit4] 2> 152648 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 152648 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 152649 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 152652 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:63812/solr/delLiveColl_shard2_replica_n4/ shard2
[junit4] 2> 152754 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-194-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-192-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152754 INFO (zkCallback-196-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152755 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152770 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 152771 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:delLiveColl s:shard1 r:core_node3 x:delLiveColl_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=delLiveColl_shard1_replica_n1&action=CREATE&numShards=2&collection=delLiveColl&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2087
[junit4] 2> 152803 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 152805 INFO (qtp1312027015-905) [n:127.0.0.1:63812_solr c:delLiveColl s:shard2 r:core_node7 x:delLiveColl_shard2_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=delLiveColl_shard2_replica_n4&action=CREATE&numShards=2&collection=delLiveColl&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2114
[junit4] 2> 152822 INFO (qtp1804021990-915) [n:127.0.0.1:50029_solr c:delLiveColl s:shard1 r:core_node5 x:delLiveColl_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=delLiveColl_shard1_replica_n2&action=CREATE&numShards=2&collection=delLiveColl&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2136
[junit4] 2> 152850 INFO (qtp884088892-933) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=delLiveColl_shard2_replica_n6&action=CREATE&numShards=2&collection=delLiveColl&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2162
[junit4] 2> 152853 INFO (qtp2113710410-918) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 152950 INFO (zkCallback-194-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152950 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152950 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152950 INFO (zkCallback-196-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152950 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152951 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152951 INFO (zkCallback-192-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 152952 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153854 INFO (qtp2113710410-918) [n:127.0.0.1:35333_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=delLiveColl&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3502
[junit4] 2> 153858 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 153860 INFO (qtp2113710410-922) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :deletereplica with params replica=core_node7&action=DELETEREPLICA&collection=delLiveColl&shard=shard2&onlyIfDown=true&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 153864 INFO (OverseerCollectionConfigSetProcessor-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 153864 ERROR (OverseerThreadFactory-524-thread-2) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: delLiveColl operation: deletereplica failed:org.apache.solr.common.SolrException: Attempted to remove replica : delLiveColl/shard2/core_node7 with onlyIfDown='true', but state is 'active'
[junit4] 2> at org.apache.solr.cloud.api.collections.DeleteReplicaCmd.deleteCore(DeleteReplicaCmd.java:218)
[junit4] 2> at org.apache.solr.cloud.api.collections.DeleteReplicaCmd.deleteReplica(DeleteReplicaCmd.java:95)
[junit4] 2> at org.apache.solr.cloud.api.collections.DeleteReplicaCmd.call(DeleteReplicaCmd.java:66)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:252)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:469)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 153870 INFO (qtp2113710410-922) [n:127.0.0.1:35333_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replica=core_node7&action=DELETEREPLICA&collection=delLiveColl&shard=shard2&onlyIfDown=true&wt=javabin&version=2} status=400 QTime=10
[junit4] 2> 153872 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :deletereplica with params replica=core_node7&action=DELETEREPLICA&collection=delLiveColl&shard=shard2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 153875 INFO (OverseerCollectionConfigSetProcessor-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 153877 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.delLiveColl.shard2.replica_n4, tag=null
[junit4] 2> 153877 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33c69809: rootName = solr_63812, domain = solr.core.delLiveColl.shard2.replica_n4, service url = null, agent id = null] for registry solr.core.delLiveColl.shard2.replica_n4 / com.codahale.metrics.MetricRegistry@47cfcbe1
[junit4] 2> 153885 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.c.SolrCore [delLiveColl_shard2_replica_n4] CLOSING SolrCore org.apache.solr.core.SolrCore@2b8d0969
[junit4] 2> 153885 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.delLiveColl.shard2.replica_n4, tag=730663273
[junit4] 2> 153885 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.delLiveColl.shard2.leader, tag=730663273
[junit4] 2> 153889 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/delLiveColl/terms/shard2 to Terms{values={core_node8=0}, version=2}
[junit4] 2> 153890 INFO (qtp1312027015-907) [n:127.0.0.1:63812_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=delLiveColl_shard2_replica_n4&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2&deleteIndex=true} status=0 QTime=14
[junit4] 2> 153894 INFO (zkCallback-194-thread-2) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 153995 INFO (zkCallback-194-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153995 INFO (zkCallback-194-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153995 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153995 INFO (zkCallback-196-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153995 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 153995 INFO (zkCallback-196-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/delLiveColl/state.json] for collection [delLiveColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 154094 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replica=core_node7&action=DELETEREPLICA&collection=delLiveColl&shard=shard2&wt=javabin&version=2} status=0 QTime=222
[junit4] 2> 154097 INFO (TEST-DeleteReplicaTest.deleteLiveReplicaTest-seed#[42FEA10594B25F6D]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteLiveReplicaTest
[junit4] 2> 154136 INFO (TEST-DeleteReplicaTest.deleteReplicaOnIndexing-seed#[42FEA10594B25F6D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteReplicaOnIndexing
[junit4] 2> 154137 INFO (qtp2113710410-922) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=deleteReplicaOnIndexing&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 154140 INFO (OverseerThreadFactory-524-thread-4) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection deleteReplicaOnIndexing
[junit4] 2> 154140 INFO (OverseerCollectionConfigSetProcessor-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 154354 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"deleteReplicaOnIndexing",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"deleteReplicaOnIndexing_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35333/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 154358 INFO (OverseerStateUpdate-72127363754164235-127.0.0.1:60830_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"deleteReplicaOnIndexing",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"deleteReplicaOnIndexing_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:63812/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 154561 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=deleteReplicaOnIndexing_shard1_replica_n1&action=CREATE&numShards=1&collection=deleteReplicaOnIndexing&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 154561 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=deleteReplicaOnIndexing_shard1_replica_n2&action=CREATE&numShards=1&collection=deleteReplicaOnIndexing&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 154677 INFO (zkCallback-192-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/deleteReplicaOnIndexing/state.json] for collection [deleteReplicaOnIndexing] has occurred - updating... (live nodes size: [4])
[junit4] 2> 154677 INFO (zkCallback-190-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/deleteReplicaOnIndexing/state.json] for collection [deleteReplicaOnIndexing] has occurred - updating... (live nodes size: [4])
[junit4] 2> 154677 INFO (zkCallback-190-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/deleteReplicaOnIndexing/state.json] for collection [deleteReplicaOnIndexing] has occurred - updating... (live nodes size: [4])
[junit4] 2> 154677 INFO (zkCallback-192-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/deleteReplicaOnIndexing/state.json] for collection [deleteReplicaOnIndexing] has occurred - updating... (live nodes size: [4])
[junit4] 2> 155588 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 155588 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 155823 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.s.IndexSchema [deleteReplicaOnIndexing_shard1_replica_n2] Schema name=minimal
[junit4] 2> 155826 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 155826 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'deleteReplicaOnIndexing_shard1_replica_n2' using configuration from collection deleteReplicaOnIndexing, trusted=true
[junit4] 2> 155827 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63812.solr.core.deleteReplicaOnIndexing.shard1.replica_n2' (registry 'solr.core.deleteReplicaOnIndexing.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 155827 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 155827 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.c.SolrCore [[deleteReplicaOnIndexing_shard1_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node2/deleteReplicaOnIndexing_shard1_replica_n2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node2/./deleteReplicaOnIndexing_shard1_replica_n2/data/]
[junit4] 2> 155827 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.s.IndexSchema [deleteReplicaOnIndexing_shard1_replica_n1] Schema name=minimal
[junit4] 2> 155829 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 155829 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'deleteReplicaOnIndexing_shard1_replica_n1' using configuration from collection deleteReplicaOnIndexing, trusted=true
[junit4] 2> 155829 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35333.solr.core.deleteReplicaOnIndexing.shard1.replica_n1' (registry 'solr.core.deleteReplicaOnIndexing.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6fd061d1
[junit4] 2> 155829 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 155829 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.c.SolrCore [[deleteReplicaOnIndexing_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node4/deleteReplicaOnIndexing_shard1_replica_n1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001/tempDir-001/node4/./deleteReplicaOnIndexing_shard1_replica_n1/data/]
[junit4] 2> 155878 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 155878 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 155878 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 155878 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 155879 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 155879 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 155879 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 155879 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 155880 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@12f25d2f[deleteReplicaOnIndexing_shard1_replica_n1] main]
[junit4] 2> 155880 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3551424d[deleteReplicaOnIndexing_shard1_replica_n2] main]
[junit4] 2> 155881 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 155882 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 155882 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 155883 INFO (qtp2113710410-919) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s:shard1 r:core_node3 x:deleteReplicaOnIndexing_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 155883 INFO (qtp1312027015-909) [n:127.0.0.1:63812_solr c:deleteReplicaOnIndexing s:shard1 r:core_node4 x:deleteReplicaOnIndexing_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 155883 INFO (searcherExecutor-554-thread-1-processing-n:127.0.0.1:35333_solr x:deleteReplicaOnIndexing_shard1_replica_n1 c:deleteReplicaOnIndexing s:shard1 r:core_node3) [n:127.0.0.1:35333_solr c:deleteReplicaOnIndexing s
[...truncated too long message...]
28849738
[junit4] 2> 208012 INFO (coreCloseExecutor-668-thread-4) [n:127.0.0.1:35333_solr c:deleteByCountNew s:shard1 r:core_node6 x:deleteByCountNew_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.deleteByCountNew.shard1.leader, tag=684777644
[junit4] 2> 208016 INFO (jetty-closer-163-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72127363754164236-127.0.0.1:50029_solr-n_0000000001) closing
[junit4] 2> 208016 INFO (OverseerStateUpdate-72127363754164236-127.0.0.1:50029_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:50029_solr
[junit4] 2> 208017 WARN (OverseerAutoScalingTriggerThread-72127363754164236-127.0.0.1:50029_solr-n_0000000001) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 208019 INFO (coreCloseExecutor-670-thread-1) [n:127.0.0.1:60830_solr c:deleteByCountNew s:shard2 r:core_node8 x:deleteByCountNew_shard2_replica_n4] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.deleteByCountNew.shard2.leader, tag=1837784222
[junit4] 2> 208020 INFO (coreCloseExecutor-670-thread-2) [n:127.0.0.1:60830_solr c:deletereplica_test s:shard1 r:core_node4 x:deletereplica_test_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.deletereplica_test.shard1.replica_n2, tag=1233594213
[junit4] 2> 208020 INFO (coreCloseExecutor-670-thread-2) [n:127.0.0.1:60830_solr c:deletereplica_test s:shard1 r:core_node4 x:deletereplica_test_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4c1131c8: rootName = solr_60830, domain = solr.core.deletereplica_test.shard1.replica_n2, service url = null, agent id = null] for registry solr.core.deletereplica_test.shard1.replica_n2 / com.codahale.metrics.MetricRegistry@2a31611f
[junit4] 2> 208030 INFO (coreCloseExecutor-670-thread-2) [n:127.0.0.1:60830_solr c:deletereplica_test s:shard1 r:core_node4 x:deletereplica_test_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.deletereplica_test.shard1.leader, tag=1233594213
[junit4] 2> 208031 INFO (coreCloseExecutor-670-thread-3) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.delLiveColl.shard2.replica_n6, tag=1078468438
[junit4] 2> 208031 INFO (coreCloseExecutor-670-thread-3) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@639bf7cc: rootName = solr_60830, domain = solr.core.delLiveColl.shard2.replica_n6, service url = null, agent id = null] for registry solr.core.delLiveColl.shard2.replica_n6 / com.codahale.metrics.MetricRegistry@1dd76fd1
[junit4] 2> 208039 INFO (coreCloseExecutor-670-thread-3) [n:127.0.0.1:60830_solr c:delLiveColl s:shard2 r:core_node8 x:delLiveColl_shard2_replica_n6] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.delLiveColl.shard2.leader, tag=1078468438
[junit4] 2> 208072 INFO (jetty-closer-163-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@52f0a999{/solr,null,UNAVAILABLE}
[junit4] 2> 208076 INFO (jetty-closer-163-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3bc12b59{/solr,null,UNAVAILABLE}
[junit4] 2> 208076 INFO (jetty-closer-163-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 208077 INFO (zkCallback-190-thread-4) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35333_solr
[junit4] 2> 208080 INFO (jetty-closer-163-thread-2) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 208134 INFO (jetty-closer-163-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@47a577ab{/solr,null,UNAVAILABLE}
[junit4] 2> 208135 INFO (jetty-closer-163-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 208155 ERROR (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-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> 208156 INFO (SUITE-DeleteReplicaTest-seed#[42FEA10594B25F6D]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47357 47357
[junit4] 2> 208206 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxnFactory Ignoring exception
[junit4] 2> java.nio.channels.ClosedChannelException: null
[junit4] 2> at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:235) ~[?:1.8.0_162]
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:207) [zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_162]
[junit4] 2> 208207 INFO (Thread-115) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:47357 47357
[junit4] 2> 208226 WARN (Thread-115) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/collections/raceDeleteReplica/terms/shard1
[junit4] 2> 14 /solr/collections/deleteByCount/terms/shard1
[junit4] 2> 13 /solr/aliases.json
[junit4] 2> 13 /solr/clusterprops.json
[junit4] 2> 10 /solr/configs/conf
[junit4] 2> 9 /solr/collections/deleteReplicaOnIndexing/terms/shard1
[junit4] 2> 8 /solr/collections/deletereplica_test/terms/shard1
[junit4] 2> 7 /solr/collections/delLiveColl/terms/shard2
[junit4] 2> 7 /solr/collections/deleteByCountNew/terms/shard2
[junit4] 2> 6 /solr/collections/deleteByCountNew/terms/shard1
[junit4] 2> 6 /solr/security.json
[junit4] 2> 5 /solr/collections/delLiveColl/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 49 /solr/collections/deleteByCountNew/state.json
[junit4] 2> 38 /solr/collections/delLiveColl/state.json
[junit4] 2> 34 /solr/collections/raceDeleteReplica/state.json
[junit4] 2> 20 /solr/collections/deleteByCount/state.json
[junit4] 2> 16 /solr/collections/deletereplica_test/state.json
[junit4] 2> 15 /solr/collections/deleteReplicaOnIndexing/state.json
[junit4] 2> 13 /solr/clusterstate.json
[junit4] 2> 3 /solr/collections/raceDeleteReplica/leader_elect/shard1/election/72127363754164234-core_node4-n_0000000000
[junit4] 2> 2 /solr/collections/deleteByCount/leader_elect/shard1/election/72127363754164233-core_node6-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/72127363754164233-127.0.0.1:35333_solr-n_0000000002
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 13 /solr/collections
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_42FEA10594B25F6D-001
[junit4] 2> Mar 26, 2018 6:01:17 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=PostingsFormat(name=LuceneVarGapFixedInterval), id=BlockTreeOrds(blocksize=128)}, docValues:{_version_=DocValuesFormat(name=Asserting), id=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=162, maxMBSortInHeap=5.428042468309821, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@409312c5), locale=ar-SA, timezone=Asia/Seoul
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=3,threads=1,free=142934920,total=316669952
[junit4] 2> NOTE: All tests run in this JVM: [TestConfigSetsAPIZkFailure, BasicFunctionalityTest, TestPolicyCloud, DOMUtilTest, SearchHandlerTest, TestSSLRandomization, TestNRTOpen, TestPullReplica, SpellCheckComponentTest, DeleteReplicaTest]
[junit4] Completed [23/786 (1!)] on J1 in 60.85s, 6 tests, 1 error <<< FAILURES!
[...truncated 52199 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1762/consoleText
[repro] Revision: df9b88443430a85c4bb00af63ff1da911584e6f5
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=DeleteReplicaTest -Dtests.method=deleteReplicaOnIndexing -Dtests.seed=42FEA10594B25F6D -Dtests.slow=true -Dtests.locale=ar-SA -Dtests.timezone=Asia/Seoul -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] DeleteReplicaTest
[repro] ant compile-test
[...truncated 3317 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.DeleteReplicaTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=42FEA10594B25F6D -Dtests.slow=true -Dtests.locale=ar-SA -Dtests.timezone=Asia/Seoul -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 93 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.DeleteReplicaTest
[repro] Exiting with code 0
[...truncated 70 lines...]
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1764 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1764/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreads
Error Message:
MockDirectoryWrapper: cannot close: there are still 27 open files: {_5_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.doc=1, _6.fdt=1, _6_LuceneVarGapDocFreqInterval_0.doc=1, _5_Lucene70_0.dvd=1, _5.fdt=1, _7_LuceneVarGapDocFreqInterval_0.pos=1, _6_LuceneVarGapDocFreqInterval_0.pos=1, _4.fdt=1, _4_LuceneVarGapDocFreqInterval_0.tib=1, _4_LuceneVarGapDocFreqInterval_0.doc=1, _6.tvd=1, _6.nvd=1, _4_Lucene70_0.dvd=1, _7.tvd=1, _5_LuceneVarGapDocFreqInterval_0.pos=1, _7.nvd=1, _4_LuceneVarGapDocFreqInterval_0.pos=1, _4.tvd=1, _6_Lucene70_0.dvd=1, _4.nvd=1, _6_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.tib=1, _5.tvd=1, _5.nvd=1, _7.fdt=1, _5_LuceneVarGapDocFreqInterval_0.doc=1}
Stack Trace:
java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 27 open files: {_5_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.doc=1, _6.fdt=1, _6_LuceneVarGapDocFreqInterval_0.doc=1, _5_Lucene70_0.dvd=1, _5.fdt=1, _7_LuceneVarGapDocFreqInterval_0.pos=1, _6_LuceneVarGapDocFreqInterval_0.pos=1, _4.fdt=1, _4_LuceneVarGapDocFreqInterval_0.tib=1, _4_LuceneVarGapDocFreqInterval_0.doc=1, _6.tvd=1, _6.nvd=1, _4_Lucene70_0.dvd=1, _7.tvd=1, _5_LuceneVarGapDocFreqInterval_0.pos=1, _7.nvd=1, _4_LuceneVarGapDocFreqInterval_0.pos=1, _4.tvd=1, _6_Lucene70_0.dvd=1, _4.nvd=1, _6_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.tib=1, _5.tvd=1, _5.nvd=1, _7.fdt=1, _5_LuceneVarGapDocFreqInterval_0.doc=1}
at __randomizedtesting.SeedInfo.seed([F6000648FD901344:97AD0EC721BE90F8]:0)
at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:841)
at org.apache.lucene.index.TestIndexWriterWithThreads._testMultipleThreadsFailure(TestIndexWriterWithThreads.java:339)
at org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreads(TestIndexWriterWithThreads.java:456)
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 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 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)
Caused by: java.lang.RuntimeException: unclosed IndexInput: _6_LuceneVarGapDocFreqInterval_0.pos
at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:732)
at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:776)
at org.apache.lucene.codecs.lucene50.Lucene50PostingsReader.<init>(Lucene50PostingsReader.java:92)
at org.apache.lucene.codecs.blockterms.LuceneVarGapDocFreqInterval.fieldsProducer(LuceneVarGapDocFreqInterval.java:100)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:293)
at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:373)
at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:113)
at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:78)
at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:208)
at org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:831)
at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4445)
at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4136)
at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
Build Log:
[...truncated 1008 lines...]
[junit4] Suite: org.apache.lucene.index.TestIndexWriterWithThreads
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestIndexWriterWithThreads -Dtests.method=testIOExceptionDuringAbortWithThreads -Dtests.seed=F6000648FD901344 -Dtests.slow=true -Dtests.locale=ar-MA -Dtests.timezone=CTT -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.06s J0 | TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreads <<<
[junit4] > Throwable #1: java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still 27 open files: {_5_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.doc=1, _6.fdt=1, _6_LuceneVarGapDocFreqInterval_0.doc=1, _5_Lucene70_0.dvd=1, _5.fdt=1, _7_LuceneVarGapDocFreqInterval_0.pos=1, _6_LuceneVarGapDocFreqInterval_0.pos=1, _4.fdt=1, _4_LuceneVarGapDocFreqInterval_0.tib=1, _4_LuceneVarGapDocFreqInterval_0.doc=1, _6.tvd=1, _6.nvd=1, _4_Lucene70_0.dvd=1, _7.tvd=1, _5_LuceneVarGapDocFreqInterval_0.pos=1, _7.nvd=1, _4_LuceneVarGapDocFreqInterval_0.pos=1, _4.tvd=1, _6_Lucene70_0.dvd=1, _4.nvd=1, _6_LuceneVarGapDocFreqInterval_0.tib=1, _7_LuceneVarGapDocFreqInterval_0.tib=1, _5.tvd=1, _5.nvd=1, _7.fdt=1, _5_LuceneVarGapDocFreqInterval_0.doc=1}
[junit4] > at __randomizedtesting.SeedInfo.seed([F6000648FD901344:97AD0EC721BE90F8]:0)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:841)
[junit4] > at org.apache.lucene.index.TestIndexWriterWithThreads._testMultipleThreadsFailure(TestIndexWriterWithThreads.java:339)
[junit4] > at org.apache.lucene.index.TestIndexWriterWithThreads.testIOExceptionDuringAbortWithThreads(TestIndexWriterWithThreads.java:456)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.lang.RuntimeException: unclosed IndexInput: _6_LuceneVarGapDocFreqInterval_0.pos
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.addFileHandle(MockDirectoryWrapper.java:732)
[junit4] > at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:776)
[junit4] > at org.apache.lucene.codecs.lucene50.Lucene50PostingsReader.<init>(Lucene50PostingsReader.java:92)
[junit4] > at org.apache.lucene.codecs.blockterms.LuceneVarGapDocFreqInterval.fieldsProducer(LuceneVarGapDocFreqInterval.java:100)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:293)
[junit4] > at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:373)
[junit4] > at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:113)
[junit4] > at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:78)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:208)
[junit4] > at org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:831)
[junit4] > at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4445)
[junit4] > at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4136)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:625)
[junit4] > at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:662)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {date=PostingsFormat(name=LuceneVarGapDocFreqInterval), field=PostingsFormat(name=LuceneVarGapDocFreqInterval), docid=BlockTreeOrds(blocksize=128), titleTokenized=PostingsFormat(name=Memory), body=PostingsFormat(name=LuceneVarGapDocFreqInterval), title=FST50}, docValues:{date=DocValuesFormat(name=Lucene70), dv=DocValuesFormat(name=Lucene70), docid_intDV=DocValuesFormat(name=Lucene70), docid_int=DocValuesFormat(name=Memory), field=DocValuesFormat(name=Lucene70), docid=DocValuesFormat(name=Memory), titleTokenized=DocValuesFormat(name=Lucene70), title=DocValuesFormat(name=Asserting), body=DocValuesFormat(name=Lucene70), titleDV=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=955, maxMBSortInHeap=6.968626066190461, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@67d42dce), locale=ar-MA, timezone=CTT
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=3,threads=1,free=130018560,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [Test2BNumericDocValues, TestBagOfPositions, TestField, TestIndexWriter, TestTerms, TestLevenshteinAutomata, TestQueryRescorer, TestAxiomaticF2EXP, TestReaderClosed, TestFieldCacheRewriteMethod, TestSpanSearchEquivalence, TestFilterWeight, TestSpanExplanationsOfNonMatches, TestCustomNorms, TestBooleanRewrites, TestDocumentsWriterDeleteQueue, TestLogMergePolicy, TestIntRange, TestDuelingCodecs, TestGraphTokenStreamFiniteStrings, TestDocInverterPerFieldErrorInfo, TestMinimize, TestPrefixRandom, TestNorms, TestLiveFieldValues, TestTopDocsCollector, TestConjunctionDISI, TestUTF32ToUTF8, TestDemo, TestSegmentTermEnum, TestIndexingSequenceNumbers, TestRegexpRandom2, TestFutureArrays, TestVersion, TestSloppyMath, TestBooleanScorer, TestReadOnlyIndex, TestInPlaceMergeSorter, TestIndexWriterExceptions, TestRegexpQuery, TestMultiMMap, TestRoaringDocIdSet, TestFlushByRamOrCountsPolicy, TestCrashCausesCorruptIndex, TestMergedIterator, FuzzyTermOnShortTermsTest, TestBlockPostingsFormat, TestIndexWriterMerging, TestThreadedForceMerge, TestCodecUtil, TestNGramPhraseQuery, TestCachingTokenFilter, TestCrash, TestIntBlockPool, TestDirectMonotonic, TestBooleanQuery, TestSortedNumericSortField, TestParallelReaderEmptyIndex, TestSpanBoostQuery, TestAssertions, TestLazyProxSkipping, TestMaxPosition, TestBasicModelIn, TestMultiCollector, TestBlockMaxConjunction, TestRAMDirectory, TestAxiomaticF3EXP, TestOperations, TestIndexableField, TestIndexTooManyDocs, Test2BPoints, Test2BTerms, TestDistributionLL, TestTopDocsMerge, TestBytesRefArray, Test2BSortedDocValuesOrds, TestCharacterUtils, TestTotalHitCountCollector, TestMergeRateLimiter, TestStandardAnalyzer, TestMultiLevelSkipList, TestNeverDelete, TestBagOfPostings, TestByteBlockPool, TestGrowableByteArrayDataOutput, TestIndependenceStandardized, TestForceMergeForever, TestIndexReaderClose, TestSpans, TestSparseFixedBitSet, TestPositiveScoresOnlyCollector, TestAtomicUpdate, TestSimilarityProvider, TestCharArrayMap, TestDateSort, TestRateLimiter, TestFieldInvertState, TestDeterminizeLexicon, TestMultiset, TestLucene60FieldInfoFormat, TestNot, TestDocValuesIndexing, TestSameScoresWithThreads, TestBooleanOr, TestBooleanQueryVisitSubscorers, TestMultiTermQueryRewrites, TestPolygon, TestIndexInput, TestLucene50CompoundFormat, TestPrefixQuery, TestGeoEncodingUtils, TestIndexWriterConfig, TestBooleanSimilarity, TestElevationComparator, TestToken, TestHighCompressionMode, TestMultiTermsEnum, TestIndexWriterLockRelease, TestSloppyPhraseQuery, TestSpanTermQuery, TestFixedLengthBytesRefArray, TestLongRangeFieldQueries, TestPerFieldDocValuesFormat, TestIndexWriterReader, TestFSTs, TestPackedInts, TestIndexWriterWithThreads]
[junit4] Completed [236/487 (1!)] on J0 in 1.54s, 12 tests, 1 error <<< FAILURES!
[...truncated 829 lines...]
[junit4] JVM J0: stdout was not empty, see: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/build/core/test/temp/junit4-J0-20180327_133004_9696061221494826150684.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: FastCompressingStoredFields, pf: LuceneVarGapFixedInterval, dvf: Asserting
[junit4] <<< JVM J0: EOF ----
[...truncated 62463 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1764/consoleText
[repro] Revision: 64c110c58d04663d4aa5d3b1dfa54e9104a2e625
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestIndexWriterWithThreads -Dtests.method=testIOExceptionDuringAbortWithThreads -Dtests.seed=F6000648FD901344 -Dtests.slow=true -Dtests.locale=ar-MA -Dtests.timezone=CTT -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] lucene/core
[repro] TestIndexWriterWithThreads
[repro] ant compile-test
[...truncated 146 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestIndexWriterWithThreads" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC" -Dtests.seed=F6000648FD901344 -Dtests.slow=true -Dtests.locale=ar-MA -Dtests.timezone=CTT -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 123 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.lucene.index.TestIndexWriterWithThreads
[repro] Exiting with code 0
[...truncated 72 lines...]
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1763 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1763/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded
Error Message:
java.util.concurrent.ExecutionException: java.io.IOException: java.util.ConcurrentModificationException
Stack Trace:
java.io.IOException: java.util.concurrent.ExecutionException: java.io.IOException: java.util.ConcurrentModificationException
at __randomizedtesting.SeedInfo.seed([DB274967BB634ABA:BEE41F1019C0E2B9]:0)
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:462)
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager$1.request(SimCloudManager.java:336)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:297)
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)
Caused by: java.util.concurrent.ExecutionException: java.io.IOException: java.util.ConcurrentModificationException
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:460)
... 42 more
Caused by: java.io.IOException: java.util.ConcurrentModificationException
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:500)
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$2(SimCloudManager.java:459)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
... 1 more
Caused by: java.util.ConcurrentModificationException
at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:909)
at java.util.ArrayList$Itr.next(ArrayList.java:859)
at org.apache.solr.cloud.autoscaling.sim.SimNodeStateProvider.getReplicaInfo(SimNodeStateProvider.java:286)
at org.apache.solr.client.solrj.cloud.autoscaling.Policy$Session.<init>(Policy.java:258)
at org.apache.solr.client.solrj.cloud.autoscaling.Policy.createSession(Policy.java:383)
at org.apache.solr.cloud.autoscaling.AutoScalingHandler.verifyAutoScalingConf(AutoScalingHandler.java:637)
at org.apache.solr.cloud.autoscaling.AutoScalingHandler.setAutoScalingConfig(AutoScalingHandler.java:624)
at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:212)
at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:145)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:195)
at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:497)
... 6 more
FAILED: org.apache.solr.cloud.DeleteReplicaTest.deleteReplicaOnIndexing
Error Message:
Time out waiting for LIR state get removed
Stack Trace:
java.util.concurrent.TimeoutException: Time out waiting for LIR state get removed
at __randomizedtesting.SeedInfo.seed([DB274967BB634ABA:A25C65E818FE8099]:0)
at org.apache.solr.util.TimeOut.waitFor(TimeOut.java:66)
at org.apache.solr.cloud.DeleteReplicaTest.deleteReplicaOnIndexing(DeleteReplicaTest.java:331)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 1841 lines...]
[junit4] JVM J0: stdout was not empty, see: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/build/core/test/temp/junit4-J0-20180327_045929_397921020713015708830.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: SimpleText, pf: TestBloomFilteredLucenePostings, dvf: Lucene70
[junit4] <<< JVM J0: EOF ----
[...truncated 10191 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[junit4] 2> 89740 INFO (SUITE-TestComputePlanAction-seed#[DB274967BB634ABA]-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-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_DB274967BB634ABA-001/init-core-data-001
[junit4] 2> 89742 WARN (SUITE-TestComputePlanAction-seed#[DB274967BB634ABA]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
[junit4] 2> 89742 INFO (SUITE-TestComputePlanAction-seed#[DB274967BB634ABA]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 89743 INFO (SUITE-TestComputePlanAction-seed#[DB274967BB634ABA]-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> 89760 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 89760 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 89762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 89763 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 89763 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 89765 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 89766 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 89767 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 89768 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 89768 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 89768 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) ~[?:1.8.0_162]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_162]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:165) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_162]
[junit4] 2> 89770 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 89770 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 89770 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 89770 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 89770 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 89771 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 89771 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 89771 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89792 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89813 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89837 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89859 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89905 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89933 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89957 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89982 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 89984 DEBUG (simCloudManagerPool-302-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 89985 DEBUG (simCloudManagerPool-302-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 89986 DEBUG (simCloudManagerPool-302-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 89987 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 89988 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 89988 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 89999 DEBUG (simCloudManagerPool-302-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 89999 DEBUG (simCloudManagerPool-302-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 89999 DEBUG (simCloudManagerPool-302-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 89999 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 90000 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90000 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 90038 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90058 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90085 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90112 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90132 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90154 DEBUG (simCloudManagerPool-302-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 90154 DEBUG (simCloudManagerPool-302-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 90155 DEBUG (simCloudManagerPool-302-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90159 DEBUG (simCloudManagerPool-302-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90159 DEBUG (simCloudManagerPool-302-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 90159 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 90160 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 90162 DEBUG (simCloudManagerPool-302-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 90162 DEBUG (simCloudManagerPool-302-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 90162 DEBUG (simCloudManagerPool-302-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90163 DEBUG (simCloudManagerPool-302-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90163 DEBUG (simCloudManagerPool-302-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 90163 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 90163 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 90165 DEBUG (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 90168 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90169 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90169 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90176 WARN (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection testNodeAdded is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 90189 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90191 DEBUG (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 90209 DEBUG (ScheduledTrigger-303-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90212 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90215 DEBUG (ScheduledTrigger-303-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90214 DEBUG (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 90230 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90235 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90235 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90268 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90269 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90269 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90277 INFO (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1105550942 sessionWrapper.createTime 1105547876588053, this.sessionWrapper.createTime 1105547876588053
[junit4] 2> 90282 DEBUG (simCloudManagerPool-302-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 90290 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90290 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90290 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90310 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90325 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90327 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90331 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90349 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90349 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90353 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90358 ERROR (simCloudManagerPool-302-thread-8) [ ] o.a.s.h.RequestHandlerBase java.util.ConcurrentModificationException
[junit4] 2> at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:909)
[junit4] 2> at java.util.ArrayList$Itr.next(ArrayList.java:859)
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimNodeStateProvider.getReplicaInfo(SimNodeStateProvider.java:286)
[junit4] 2> at org.apache.solr.client.solrj.cloud.autoscaling.Policy$Session.<init>(Policy.java:258)
[junit4] 2> at org.apache.solr.client.solrj.cloud.autoscaling.Policy.createSession(Policy.java:383)
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.verifyAutoScalingConf(AutoScalingHandler.java:637)
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.setAutoScalingConfig(AutoScalingHandler.java:624)
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:212)
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:145)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:195)
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:497)
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$2(SimCloudManager.java:459)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 90359 DEBUG (simCloudManagerPool-302-thread-8) [ ] o.a.s.c.a.s.SimCloudManager -- exception handling request
[junit4] 2> java.util.ConcurrentModificationException: null
[junit4] 2> at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:909) ~[?:1.8.0_162]
[junit4] 2> at java.util.ArrayList$Itr.next(ArrayList.java:859) ~[?:1.8.0_162]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimNodeStateProvider.getReplicaInfo(SimNodeStateProvider.java:286) ~[test/:?]
[junit4] 2> at org.apache.solr.client.solrj.cloud.autoscaling.Policy$Session.<init>(Policy.java:258) ~[java/:?]
[junit4] 2> at org.apache.solr.client.solrj.cloud.autoscaling.Policy.createSession(Policy.java:383) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.verifyAutoScalingConf(AutoScalingHandler.java:637) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.setAutoScalingConfig(AutoScalingHandler.java:624) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:212) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:145) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:195) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:497) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$2(SimCloudManager.java:459) ~[test/:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_162]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_162]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_162]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_162]
[junit4] 2> 90363 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 90365 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {"127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 90366 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10000_solr]
[junit4] 2> 90368 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeAdded state: DocCollection(testNodeAdded//clusterstate.json/2)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 90370 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90370 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 90370 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 90371 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 90371 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 90372 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testNodeAdded]
[junit4] 2> 90372 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
[junit4] 2> 90372 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 2
[junit4] 2> 90372 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
[junit4] 2> 90373 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeAdded 2
[junit4] 2> 90374 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90374 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
[junit4] 2> 90374 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 90382 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 90382 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 5
[junit4] 2> 90382 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 90392 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90392 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90394 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeAdded -Dtests.seed=DB274967BB634ABA -Dtests.slow=true -Dtests.locale=und -Dtests.timezone=Asia/Ulan_Bator -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 0.64s J0 | TestComputePlanAction.testNodeAdded <<<
[junit4] > Throwable #1: java.io.IOException: java.util.concurrent.ExecutionException: java.io.IOException: java.util.ConcurrentModificationException
[junit4] > at __randomizedtesting.SeedInfo.seed([DB274967BB634ABA:BEE41F1019C0E2B9]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:462)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager$1.request(SimCloudManager.java:336)
[junit4] > at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:297)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.util.concurrent.ExecutionException: java.io.IOException: java.util.ConcurrentModificationException
[junit4] > at java.util.concurrent.FutureTask.report(FutureTask.java:122)
[junit4] > at java.util.concurrent.FutureTask.get(FutureTask.java:192)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:460)
[junit4] > ... 42 more
[junit4] > Caused by: java.io.IOException: java.util.ConcurrentModificationException
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:500)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$2(SimCloudManager.java:459)
[junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] > ... 1 more
[junit4] > Caused by: java.util.ConcurrentModificationException
[junit4] > at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:909)
[junit4] > at java.util.ArrayList$Itr.next(ArrayList.java:859)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimNodeStateProvider.getReplicaInfo(SimNodeStateProvider.java:286)
[junit4] > at org.apache.solr.client.solrj.cloud.autoscaling.Policy$Session.<init>(Policy.java:258)
[junit4] > at org.apache.solr.client.solrj.cloud.autoscaling.Policy.createSession(Policy.java:383)
[junit4] > at org.apache.solr.cloud.autoscaling.AutoScalingHandler.verifyAutoScalingConf(AutoScalingHandler.java:637)
[junit4] > at org.apache.solr.cloud.autoscaling.AutoScalingHandler.setAutoScalingConfig(AutoScalingHandler.java:624)
[junit4] > at org.apache.solr.cloud.autoscaling.AutoScalingHandler.processOps(AutoScalingHandler.java:212)
[junit4] > at org.apache.solr.cloud.autoscaling.AutoScalingHandler.handleRequestBody(AutoScalingHandler.java:145)
[junit4] > at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:195)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:497)
[junit4] > ... 6 more
[junit4] 2> 90447 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90447 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90447 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90470 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90470 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90470 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90495 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90495 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90499 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90527 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 90527 DEBUG (ScheduledTrigger-303-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 90527 DEBUG (ScheduledTrigger-303-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90532 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 90532 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 90532 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 90533 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 90533 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90533 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 90534 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 90534 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2034) ~[?:1.8.0_162]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_162]
[junit4] 2> 90535 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 90537 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 90538 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 90538 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion -1
[junit4] 2> 90539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 90539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 90540 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90569 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90590 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90619 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90640 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90659 DEBUG (simCloudManagerPool-305-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 90661 DEBUG (simCloudManagerPool-305-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 90670 DEBUG (simCloudManagerPool-305-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90670 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90672 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 90673 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90673 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 90673 DEBUG (simCloudManagerPool-305-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 90673 DEBUG (simCloudManagerPool-305-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 90674 DEBUG (simCloudManagerPool-305-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 90674 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 90675 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90675 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 90692 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90715 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90740 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90775 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 90777 DEBUG (simCloudManagerPool-305-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 90777 DEBUG (simCloudManagerPool-305-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 90777 DEBUG (simCloudManagerPool-305-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 90778 DEBUG (simCloudManagerPool-305-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 90779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 90779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 90779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 90779 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90780 DEBUG (simCloudManagerPool-305-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
[junit4] 2> 90792 DEBUG (simCloudManagerPool-305-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 90793 DEBUG (simCloudManagerPool-305-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 90800 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90801 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90809 INFO (simCloudManagerPool-305-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1105577592 sessionWrapper.createTime 1105576766239853, this.sessionWrapper.createTime 1105576766239853
[junit4] 2> 90809 DEBUG (simCloudManagerPool-305-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 90822 DEBUG (ScheduledTrigger-306-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90830 DEBUG (ScheduledTrigger-306-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90832 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 6
[junit4] 2> live nodes:[127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/5)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 90845 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90846 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction Stopped_node : 127.0.0.1:10001_solr
[junit4] 2> 90845 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
[junit4] 2> 90851 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90851 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
[junit4] 2> 90853 DEBUG (simCloudManagerPool-305-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: {"core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeLost"}}
[junit4] 2> 90867 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90871 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90887 DEBUG (ScheduledTrigger-306-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90892 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90909 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90912 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90930 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90933 DEBUG (ScheduledTrigger-306-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90950 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90954 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90974 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90975 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90996 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 90996 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 90996 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10001_solr]
[junit4] 2> 91000 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3ed84d39a5dadT4ghws7nzh5gzl9lgu9uitowji",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105579671707053,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105579671707053],
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 91001 DEBUG (ScheduledTrigger-306-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 91034 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3ed84d39a5dadT4ghws7nzh5gzl9lgu9uitowji",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105579671707053,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105579671707053],
[junit4] 2> "_enqueue_time_":1105587256084453,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 91036 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"3ed84d39a5dadT4ghws7nzh5gzl9lgu9uitowji",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105579671707053,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105579671707053],
[junit4] 2> "_enqueue_time_":1105587256084453,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 91036 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 91057 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 91063 INFO (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10002_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 91064 INFO (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1105590320 sessionWrapper.createTime 1105590005304803, this.sessionWrapper.createTime 1105590005304803
[junit4] 2> 91064 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 91081 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 91081 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 91081 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 91081 DEBUG (AutoscalingActionExecutor-307-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 2385 ms for event id=3ed84d39a5dadT4ghws7nzh5gzl9lgu9uitowji
[junit4] 2> 91082 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 91082 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10002_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":0,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1000,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10002_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10002,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 91082 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10000_solr]
[junit4] 2> 91082 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/7)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLost
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 2
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10001_solr
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10002_solr
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testNodeLost]
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeLost 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 3
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4
[junit4] 2> 91083 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 91084 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 91085 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - AFTER_ACTION 1
[junit4] 2> 91085 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - BEFORE_ACTION 1
[junit4] 2> 91085 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 91085 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 91124 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 91124 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 91124 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10001_solr
[junit4] 2> 91124 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10002_solr
[junit4] 2> 91124 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 91125 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 91127 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 91130 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 91130 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 91131 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 91131 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion -1
[junit4] 2> 91131 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 91132 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 91132 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 91133 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91154 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91174 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91195 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91217 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91245 DEBUG (simCloudManagerPool-308-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 91246 DEBUG (simCloudManagerPool-308-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 91246 DEBUG (simCloudManagerPool-308-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 91246 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 91247 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 91247 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 91247 DEBUG (simCloudManagerPool-308-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 91247 DEBUG (simCloudManagerPool-308-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 91248 DEBUG (simCloudManagerPool-308-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 91248 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 91248 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 91248 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 91250 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91275 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91297 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91317 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91342 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 91351 DEBUG (simCloudManagerPool-308-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 91351 DEBUG (simCloudManagerPool-308-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 91352 DEBUG (simCloudManagerPool-308-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 91352 DEBUG (simCloudManagerPool-308-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
[junit4] 2> 91352 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 91353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 91353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 91353 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 91353 DEBUG (simCloudManagerPool-308-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
[junit4] 2> 91364 DEBUG (simCloudManagerPool-308-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 91365 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 91366 DEBUG (simCloudManagerPool-308-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 91373 INFO (simCloudManagerPool-308-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1105605789 sessionWrapper.createTime 1105605450090853, this.sessionWrapper.createTime 1105605450090853
[junit4] 2> 91373 DEBUG (simCloudManagerPool-308-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 91373 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 91386 DEBUG (ScheduledTrigger-309-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 91395 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 91407 DEBUG (ScheduledTrigger-309-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 91416 DEBUG (ScheduledTrigger-309-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 91427 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 91436 DEBUG (ScheduledTrigger-309-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 91436 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 10
[junit4] 2> live nodes:[127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr, 127.0.0.1:10005_solr]
[junit4] 2> collections:{testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/9)={
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node4":{
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node5":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node3":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 91438 DEBUG (simCloudManagerPool-308-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"core_node6":{
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}}
[junit4] 2> 91441 DEBUG (simCloudManagerPool-308-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}}
[junit4] 2> 91451 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 91451 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10005_solr
[junit4] 2> 91456 DEBUG (ScheduledTrigger-309-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 91456 DEBUG (ScheduledTrigger-309-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10005_solr
[junit4] 2> 91472 DEBUG (ScheduledTrigger-309-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 91477 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 91477 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10005_solr]
[junit4] 2> 91477 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3ed8be1087e87T4ghws7nzh5gzl9lgu9uitowjn",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105609961799303,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105609961799303],
[junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}}
[junit4] 2> 91477 DEBUG (ScheduledTrigger-309-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 91479 DEBUG (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3ed8be1087e87T4ghws7nzh5gzl9lgu9uitowjn",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105609961799303,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105609961799303],
[junit4] 2> "_enqueue_time_":1105611024064003,
[junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}}
[junit4] 2> 91480 DEBUG (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"3ed8be1087e87T4ghws7nzh5gzl9lgu9uitowjn",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1105609961799303,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1105609961799303],
[junit4] 2> "_enqueue_time_":1105611024064003,
[junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 91480 DEBUG (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 91480 DEBUG (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 91484 INFO (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node5
[junit4] 2> 91484 INFO (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10004_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 91484 INFO (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1105611357 sessionWrapper.createTime 1105611149003253, this.sessionWrapper.createTime 1105611149003253
[junit4] 2> 91484 DEBUG (AutoscalingActionExecutor-310-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 91486 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node5
[junit4] 2> 91486 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10004_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 91487 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 91487 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[DB274967BB634ABA]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10004_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10004_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10004,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10005_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10005_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10005,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10003_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_162",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2>
[...truncated too long message...]
ion/72130179964076044-127.0.0.1:47472_solr-n_0000000001
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 13 /solr/collections
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.DeleteReplicaTest_DB274967BB634ABA-001
[junit4] 2> Mar 27, 2018 5:57:08 AM 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): {id=PostingsFormat(name=MockRandom)}, docValues:{}, maxPointsInLeafNode=356, maxMBSortInHeap=7.078864256527621, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4b6964fc), locale=he-IL, timezone=Europe/Brussels
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_162 (64-bit)/cpus=3,threads=1,free=128983592,total=490704896
[junit4] 2> NOTE: All tests run in this JVM: [TestSolrConfigHandler, TestConfig, TestConfigSetsAPI, TestLegacyFieldReuse, HttpTriggerListenerTest, DirectUpdateHandlerTest, TestAnalyzeInfixSuggestions, TestDFRSimilarityFactory, RestartWhileUpdatingTest, TestIntervalFaceting, TestPushWriter, TestOverriddenPrefixQueryForCustomFieldType, TestRandomFaceting, TestGenericDistributedQueue, TestRandomCollapseQParserPlugin, MigrateRouteKeyTest, ShardRoutingTest, HttpSolrCallGetCoreTest, TestFastLRUCache, BadComponentTest, CircularListTest, ZkStateReaderTest, TestLegacyTerms, V2StandaloneTest, ConfigureRecoveryStrategyTest, BasicAuthStandaloneTest, IndexBasedSpellCheckerTest, RequestLoggingTest, TestSortByMinMaxFunction, LeaderFailoverAfterPartitionTest, TestPolicyCloud, SpellCheckComponentTest, TestSolrDeletionPolicy2, BadIndexSchemaTest, ZkControllerTest, CreateRoutedAliasTest, SharedFSAutoReplicaFailoverTest, TestDocSet, TestBinaryResponseWriter, TestRTGBase, SimpleMLTQParserTest, CoreAdminRequestStatusTest, InfoHandlerTest, UpdateParamsTest, TestGraphMLResponseWriter, ClusterStateUpdateTest, ScheduledMaintenanceTriggerTest, AutoAddReplicasIntegrationTest, SyncSliceTest, TestExceedMaxTermLength, TestNRTOpen, TestCollectionAPI, HdfsRecoverLeaseTest, FullHLLTest, TestStressReorder, TestNumericRangeQuery32, TestNodeAddedTrigger, NodeMutatorTest, TermVectorComponentTest, HLLUtilTest, PrimitiveFieldTypeTest, TestTolerantUpdateProcessorCloud, ScriptEngineTest, UUIDFieldTest, TestQuerySenderListener, DistributedExpandComponentTest, TestReloadDeadlock, TestLMDirichletSimilarityFactory, RegexBoostProcessorTest, DeleteLastCustomShardedReplicaTest, TestFieldCollectionResource, TestDelegationWithHadoopAuth, DocValuesNotIndexedTest, CheckHdfsIndexTest, TestComplexPhraseQParserPlugin, SolrJmxReporterCloudTest, TestMinMaxOnMultiValuedField, TestDFISimilarityFactory, OverseerStatusTest, DataDrivenBlockJoinTest, SolrGangliaReporterTest, TestEmbeddedSolrServerSchemaAPI, TestHdfsCloudBackupRestore, MergeStrategyTest, UninvertDocValuesMergePolicyTest, TestReRankQParserPlugin, TestConfigsApi, SubstringBytesRefFilterTest, TestConfigReload, TestShardHandlerFactory, NodeAddedTriggerTest, TestCollapseQParserPlugin, CollectionTooManyReplicasTest, TestSimpleQParserPlugin, TestStressLucene, TestDynamicFieldCollectionResource, TestDefaultStatsCache, TestConfigSetsAPIZkFailure, TestCloudManagedSchema, ReplaceNodeTest, TestSolrCloudWithHadoopAuthPlugin, SolrIndexMetricsTest, SchemaApiFailureTest, TestLuceneMatchVersion, TestCloudJSONFacetJoinDomain, SortByFunctionTest, SSLMigrationTest, DisMaxRequestHandlerTest, JsonLoaderTest, QueryParsingTest, TestPolicyCloud, DirectoryFactoryTest, TestXmlQParser, TestValueSourceCache, JvmMetricsTest, TestRawTransformer, JavabinLoaderTest, CSVRequestHandlerTest, TestTriggerIntegration, TestCrossCoreJoin, AtomicUpdatesTest, DistributedSpellCheckComponentTest, BlockJoinFacetSimpleTest, BasicFunctionalityTest, DocValuesMultiTest, DistributedFacetPivotWhiteBoxTest, TestRandomDVFaceting, TestStressRecovery, SimplePostToolTest, TestHashPartitioner, TestSolrQueryResponse, TestSolrIndexConfig, TestPerFieldSimilarityWithDefaultOverride, HdfsChaosMonkeySafeLeaderTest, HdfsUnloadDistributedZkTest, CustomHighlightComponentTest, TestAnalyzedSuggestions, LeaderVoteWaitTimeoutTest, TestInfoStreamLogging, ReplicaListTransformerTest, ConcurrentCreateRoutedAliasTest, SuggesterTest, DefaultValueUpdateProcessorTest, TestSolrConfigHandlerCloud, AddReplicaTest, TestRandomFlRTGCloud, SpellCheckCollatorTest, SpatialRPTFieldTypeTest, ManagedSchemaRoundRobinCloudTest, HdfsDirectoryTest, AnalyticsQueryTest, CdcrRequestHandlerTest, TestEmbeddedSolrServerAdminHandler, TestCloudDeleteByQuery, TestExtendedDismaxParser, ConnectionReuseTest, CustomCollectionTest, BooleanFieldTest, TestSolr4Spatial2, TestDistributedMap, DistributedQueryComponentOptimizationTest, HealthCheckHandlerTest, ChaosMonkeySafeLeaderTest, TestSolrCloudWithKerberosAlt, MetricUtilsTest, DebugComponentTest, AssignTest, CdcrBidirectionalTest, TestSolrQueryParser, TestIndexingPerformance, JSONWriterTest, TestOnReconnectListenerSupport, LoggingHandlerTest, TestLRUCache, TestWriterPerf, TestUseDocValuesAsStored2, PropertiesRequestHandlerTest, TestSolrFieldCacheBean, XsltUpdateRequestHandlerTest, SpatialHeatmapFacetsTest, TestShortCircuitedRequests, ShowFileRequestHandlerTest, DeleteStatusTest, IndexSchemaTest, HDFSCollectionsAPITest, TestFieldCacheWithThreads, DistribDocExpirationUpdateProcessorTest, TestLeaderElectionZkExpiry, AssignBackwardCompatibilityTest, SolrCloudExampleTest, TestUninvertingReader, SegmentsInfoRequestHandlerTest, FileBasedSpellCheckerTest, FacetPivotSmallTest, TestDistributedMissingSort, TestDistributedGrouping, TestRealTimeGet, TestStressVersions, DistributedTermsComponentTest, TestSolr4Spatial, StatsComponentTest, TestSort, TestFunctionQuery, TestLazyCores, TestCoreDiscovery, SuggesterFSTTest, CoreAdminHandlerTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, TestTrie, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, TestUpdate, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, StatelessScriptUpdateProcessorFactoryTest, DistanceFunctionTest, TestSurroundQueryParser, LukeRequestHandlerTest, TestQueryUtils, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TermsComponentTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestJmxIntegration, TestCollationField, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, PingRequestHandlerTest, TestComponentsName, TestLFUCache, HighlighterConfigTest, SOLR749Test, AlternateDirectoryTest, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest, SampleTest, TestBinaryField, TestSearchPerf, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, EchoParamsTest, TestSweetSpotSimilarityFactory, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, TestFastWriter, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, ChaosMonkeyNothingIsSafeTest, ChaosMonkeySafeLeaderWithPullReplicasTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionPropsTest, CollectionStateFormat2Test, CreateCollectionCleanupTest, DeleteReplicaTest]
[junit4] Completed [544/786 (2!)] on J1 in 66.91s, 6 tests, 1 error <<< FAILURES!
[...truncated 50454 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1763/consoleText
[repro] Revision: ecb94ba4422d1ed70bd368e7aa562012cc3853ba
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseConcMarkSweepGC"
[repro] Repro line: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeAdded -Dtests.seed=DB274967BB634ABA -Dtests.slow=true -Dtests.locale=und -Dtests.timezone=Asia/Ulan_Bator -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] Repro line: ant test -Dtestcase=DeleteReplicaTest -Dtests.method=deleteReplicaOnIndexing -Dtests.seed=DB274967BB634ABA -Dtests.slow=true -Dtests.locale=he-IL -Dtests.timezone=Europe/Brussels -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestComputePlanAction
[repro] DeleteReplicaTest
[repro] ant compile-test
[...truncated 3317 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=10 -Dtests.class="*.TestComputePlanAction|*.DeleteReplicaTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseConcMarkSweepGC" -Dtests.seed=DB274967BB634ABA -Dtests.slow=true -Dtests.locale=und -Dtests.timezone=Asia/Ulan_Bator -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 124 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.DeleteReplicaTest
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[repro] Exiting with code 0
[...truncated 70 lines...]