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/24 02:55:46 UTC
[JENKINS] Lucene-Solr-master-Linux (32bit/jdk1.8.0_162) - Build #
21690 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21690/
Java: 32bit/jdk1.8.0_162 -client -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.AddReplicaTest.test
Error Message:
core_node6:{"core":"addreplicatest_coll_shard1_replica_n5","base_url":"http://127.0.0.1:35791/solr","node_name":"127.0.0.1:35791_solr","state":"active","type":"NRT"}
Stack Trace:
java.lang.AssertionError: core_node6:{"core":"addreplicatest_coll_shard1_replica_n5","base_url":"http://127.0.0.1:35791/solr","node_name":"127.0.0.1:35791_solr","state":"active","type":"NRT"}
at __randomizedtesting.SeedInfo.seed([627E21DB037B0634:EA2A1E01AD876BCC]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.AddReplicaTest.test(AddReplicaTest.java:84)
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 1849 lines...]
[junit4] JVM J1: stdout was not empty, see: /home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/core/test/temp/junit4-J1-20180324_013116_5629092578696010180159.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] codec: DummyCompressingStoredFields, pf: MockRandom, dvf: Asserting
[junit4] <<< JVM J1: EOF ----
[...truncated 11362 lines...]
[junit4] Suite: org.apache.solr.cloud.AddReplicaTest
[junit4] 2> 979579 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/init-core-data-001
[junit4] 2> 979580 WARN (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 979580 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 979582 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 979582 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001
[junit4] 2> 979582 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 979583 INFO (Thread-2367) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 979583 INFO (Thread-2367) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 979588 ERROR (Thread-2367) [ ] 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> 979683 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35393
[junit4] 2> 979685 INFO (zkConnectionManagerCallback-2364-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979691 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 979691 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 979691 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 979691 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T15:27:37-06:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 979697 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 979697 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 979697 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 979698 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 979698 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 979698 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@c61ee{/solr,null,AVAILABLE}
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@858f34{/solr,null,AVAILABLE}
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 979699 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 979700 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@77a905{HTTP/1.1,[http/1.1]}{127.0.0.1:41741}
[junit4] 2> 979701 INFO (jetty-launcher-2361-thread-4) [ ] o.e.j.s.Server Started @980801ms
[junit4] 2> 979701 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41741}
[junit4] 2> 979701 ERROR (jetty-launcher-2361-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 979700 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3cf78a{/solr,null,AVAILABLE}
[junit4] 2> 979700 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@14a9a9d{HTTP/1.1,[http/1.1]}{127.0.0.1:33253}
[junit4] 2> 979701 INFO (jetty-launcher-2361-thread-3) [ ] o.e.j.s.Server Started @980801ms
[junit4] 2> 979701 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33253}
[junit4] 2> 979701 ERROR (jetty-launcher-2361-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 979701 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-24T02:16:37.807Z
[junit4] 2> 979702 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-24T02:16:37.807Z
[junit4] 2> 979703 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@11c1a54{/solr,null,AVAILABLE}
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@157882a{HTTP/1.1,[http/1.1]}{127.0.0.1:35791}
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.e.j.s.Server Started @980809ms
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35791}
[junit4] 2> 979709 ERROR (jetty-launcher-2361-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-24T02:16:37.814Z
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@12f4364{HTTP/1.1,[http/1.1]}{127.0.0.1:36249}
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-2) [ ] o.e.j.s.Server Started @980809ms
[junit4] 2> 979709 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36249}
[junit4] 2> 979710 ERROR (jetty-launcher-2361-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 979710 INFO (zkConnectionManagerCallback-2366-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979710 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 979710 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 979710 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 979710 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-24T02:16:37.815Z
[junit4] 2> 979710 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 979711 INFO (zkConnectionManagerCallback-2368-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979711 INFO (zkConnectionManagerCallback-2370-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979711 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 979712 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 979712 INFO (zkConnectionManagerCallback-2372-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979713 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 979719 INFO (jetty-launcher-2361-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35393/solr
[junit4] 2> 979722 INFO (jetty-launcher-2361-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35393/solr
[junit4] 2> 979725 INFO (jetty-launcher-2361-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35393/solr
[junit4] 2> 979726 INFO (zkConnectionManagerCallback-2376-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979728 INFO (zkConnectionManagerCallback-2381-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979729 DEBUG (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$271/26656235@1e84759
[junit4] 2> 979729 INFO (zkConnectionManagerCallback-2384-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979729 INFO (jetty-launcher-2361-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35393/solr
[junit4] 2> 979730 INFO (zkConnectionManagerCallback-2388-thread-1-processing-n:127.0.0.1:41741_solr) [n:127.0.0.1:41741_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979730 DEBUG (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$271/26656235@1bf54f0
[junit4] 2> 979731 DEBUG (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$271/26656235@1e54ba2
[junit4] 2> 979733 INFO (zkConnectionManagerCallback-2392-thread-1-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979733 INFO (zkConnectionManagerCallback-2390-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979733 INFO (zkConnectionManagerCallback-2394-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979734 DEBUG (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.ZkController Added new OnReconnect listener org.apache.solr.cloud.ZkController$$Lambda$271/26656235@128e914
[junit4] 2> 979735 INFO (zkConnectionManagerCallback-2396-thread-1-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979836 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 979837 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979837 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 979837 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 979837 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 979838 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 979839 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 979840 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 979841 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979841 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 979841 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 979841 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 979841 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 979841 DEBUG (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72188364885852171-127.0.0.1:35791_solr-n_0000000000
[junit4] 2> 979841 DEBUG (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72188364885852170-127.0.0.1:36249_solr-n_0000000001
[junit4] 2> 979841 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 979841 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35791_solr
[junit4] 2> 979841 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 979842 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72188364885852171-127.0.0.1:35791_solr-n_0000000000
[junit4] 2> 979842 DEBUG (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72188364885852171-127.0.0.1:35791_solr-n_0000000000 to know if I could be the leader
[junit4] 2> 979842 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 979842 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/security.json
[junit4] 2> 979842 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36249_solr
[junit4] 2> 979842 DEBUG (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72188364885852168-127.0.0.1:41741_solr-n_0000000002
[junit4] 2> 979842 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer Overseer (id=72188364885852171-127.0.0.1:35791_solr-n_0000000000) starting
[junit4] 2> 979842 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72188364885852170-127.0.0.1:36249_solr-n_0000000001
[junit4] 2> 979843 DEBUG (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72188364885852170-127.0.0.1:36249_solr-n_0000000001 to know if I could be the leader
[junit4] 2> 979843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979843 DEBUG (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:41741_solr as DOWN
[junit4] 2> 979843 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 979844 DEBUG (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/72188364885852172-127.0.0.1:33253_solr-n_0000000003
[junit4] 2> 979844 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/overseer_elect/election/72188364885852168-127.0.0.1:41741_solr-n_0000000002
[junit4] 2> 979844 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41741_solr
[junit4] 2> 979844 DEBUG (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/72188364885852168-127.0.0.1:41741_solr-n_0000000002 to know if I could be the leader
[junit4] 2> 979844 DEBUG (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:33253_solr as DOWN
[junit4] 2> 979845 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979846 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33253_solr
[junit4] 2> 979868 INFO (zkCallback-2393-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 979872 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979872 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979873 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979873 INFO (zkCallback-2393-thread-2-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 979881 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979885 INFO (zkCallback-2387-thread-1-processing-n:127.0.0.1:41741_solr) [n:127.0.0.1:41741_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 979885 INFO (zkCallback-2395-thread-1-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 979885 INFO (zkCallback-2391-thread-1-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 979908 INFO (zkConnectionManagerCallback-2404-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979909 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 979910 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979910 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 979910 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 979910 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 979910 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 979911 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35393/solr ready
[junit4] 2> 979911 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations
[junit4] 2> 979911 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 979914 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue-work
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 979914 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 979914 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 979914 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 979915 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 0, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:41741_solr"} current state version: 0
[junit4] 2> 979915 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:41741_solr
[junit4] 2> 979915 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 0, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:33253_solr"} current state version: 0
[junit4] 2> 979915 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:33253_solr
[junit4] 2> 979917 DEBUG (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:35791_solr as DOWN
[junit4] 2> 979918 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 979918 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/autoscaling.json
[junit4] 2> 979918 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 979919 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 979919 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35791_solr
[junit4] 2> 979919 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 979919 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979920 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979920 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979920 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979920 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/live_nodes
[junit4] 2> 979926 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979926 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979926 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979926 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979926 INFO (zkCallback-2395-thread-1-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 979926 INFO (zkCallback-2387-thread-1-processing-n:127.0.0.1:41741_solr) [n:127.0.0.1:41741_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 979927 INFO (zkCallback-2391-thread-1-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 979927 INFO (zkCallback-2393-thread-2-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 979933 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:35791_solr"} current state version: 0
[junit4] 2> 979933 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:35791_solr
[junit4] 2> 979934 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 979943 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:36249_solr, 127.0.0.1:33253_solr, 127.0.0.1:41741_solr]
[junit4] 2> 979944 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 979944 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 979954 INFO (zkCallback-2403-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 979954 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 979972 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 979973 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 979973 DEBUG (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 979973 DEBUG (ScheduledTrigger-3657-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 980034 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 980035 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 980975 DEBUG (ScheduledTrigger-3657-thread-3) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 981353 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33253.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 981392 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33253.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 981393 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33253.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 981395 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node3/.
[junit4] 2> 981456 INFO (zkConnectionManagerCallback-2408-thread-1-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 981457 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 981458 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 981458 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 981458 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 981458 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 981458 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 981459 INFO (jetty-launcher-2361-thread-3) [n:127.0.0.1:33253_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35393/solr ready
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Got 0 tasks from work-queue : [[]]
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 981915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 981975 DEBUG (ScheduledTrigger-3657-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 982391 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36249.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 982405 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36249.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 982405 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36249.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 982407 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node2/.
[junit4] 2> 982432 INFO (zkConnectionManagerCallback-2412-thread-1-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 982433 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 982434 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 982434 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 982434 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 982434 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 982434 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 982434 INFO (jetty-launcher-2361-thread-2) [n:127.0.0.1:36249_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35393/solr ready
[junit4] 2> 982976 DEBUG (ScheduledTrigger-3657-thread-3) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 983211 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41741.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 983222 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41741.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 983223 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41741.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 983224 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node4/.
[junit4] 2> 983227 INFO (zkConnectionManagerCallback-2416-thread-1-processing-n:127.0.0.1:41741_solr) [n:127.0.0.1:41741_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 983228 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 983228 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 983228 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 983228 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 983228 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 983229 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 983229 INFO (jetty-launcher-2361-thread-4) [n:127.0.0.1:41741_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35393/solr ready
[junit4] 2> 983915 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Got 0 tasks from work-queue : [[]]
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 0
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: []
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: []
[junit4] 2> 983916 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 100 elements. ExcludeSet: []
[junit4] 2> 983976 DEBUG (ScheduledTrigger-3657-thread-2) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 984531 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35791.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 984543 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35791.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 984543 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35791.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 984545 INFO (jetty-launcher-2361-thread-1) [n:127.0.0.1:35791_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node1/.
[junit4] 2> 984591 INFO (zkConnectionManagerCallback-2418-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 984595 INFO (zkConnectionManagerCallback-2422-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 984595 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/clusterprops.json
[junit4] 2> 984595 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/live_nodes
[junit4] 2> 984595 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 984596 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/clusterstate.json
[junit4] 2> 984596 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984596 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/aliases.json
[junit4] 2> 984596 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35393/solr ready
[junit4] 2> 984636 INFO (TEST-AddReplicaTest.test-seed#[627E21DB037B0634]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 984637 INFO (zkConnectionManagerCallback-2424-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 984641 INFO (qtp956222-9715) [n:127.0.0.1:33253_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf1&maxShardsPerNode=2&name=addreplicatest_coll&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 984641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 984641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/overseer/collection-queue-work/qnr-0000000000
[junit4] 2> 984641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 984641 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 984641 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/collection-queue-work
[junit4] 2> 984642 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/collection-queue-work
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.ZkDistributedQueue Found child node with improper name: qnr-0000000000
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskQueue Returning topN elements: [/overseer/collection-queue-work/qn-0000000000, ]
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Got 1 tasks from work-queue : [[org.apache.solr.cloud.OverseerTaskQueue$QueueEvent@2e684ecf]]
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Marked task [/overseer/collection-queue-work/qn-0000000000] as running
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Overseer Collection Message Handler: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"}
[junit4] 2> 984642 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Runner processing /overseer/collection-queue-work/qn-0000000000
[junit4] 2> 984642 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler OverseerCollectionMessageHandler.processMessage : create , {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"}
[junit4] 2> 984642 INFO (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection addreplicatest_coll
[junit4] 2> 984642 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor Cleaning up work-queue. #Running tasks: 1
[junit4] 2> 984643 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 984643 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor BlockedTasks: []
[junit4] 2> 984643 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor CompletedTasks: []
[junit4] 2> 984643 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskProcessor RunningZKTasks: [/overseer/collection-queue-work/qn-0000000000]
[junit4] 2> 984643 DEBUG (OverseerCollectionConfigSetProcessor-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.OverseerTaskQueue Peeking for top 99 elements. ExcludeSet: [/overseer/collection-queue-work/qn-0000000000],[]
[junit4] 2> 984643 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.Assign Identify nodes using default
[junit4] 2> 984643 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler creating collections conf node /collections/addreplicatest_coll
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984644 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984644 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Check for collection zkNode:addreplicatest_coll
[junit4] 2> 984645 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984645 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984645 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984645 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Collection zkNode exists
[junit4] 2> 984646 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984646 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984646 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 984646 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: addreplicatest_coll
[junit4] 2> 984646 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/addreplicatest_coll/state.json
[junit4] 2> 984647 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984648 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984648 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/collections
[junit4] 2> 984648 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984746 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Creating SolrCores for new collection addreplicatest_coll, shardNames [shard1, shard2] , message : {
[junit4] 2> "name":"addreplicatest_coll",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"}
[junit4] 2> 984747 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Creating core addreplicatest_coll_shard1_replica_n1 as part of shard shard1 of collection addreplicatest_coll on 127.0.0.1:33253_solr
[junit4] 2> 984748 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984748 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984749 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 984749 INFO (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 984749 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.CreateCollectionCmd Creating core addreplicatest_coll_shard2_replica_n2 as part of shard shard2 of collection addreplicatest_coll on 127.0.0.1:36249_solr
[junit4] 2> 984749 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 984750 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 984750 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984750 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984750 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Expecting [addreplicatest_coll_shard1_replica_n1, addreplicatest_coll_shard2_replica_n2] cores but found {}
[junit4] 2> 984750 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 984750 INFO (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 984751 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator Old Slice: shard2:{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 984751 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.SliceMutator New Slice: shard2:{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 984851 DEBUG (OverseerThreadFactory-3659-thread-1-processing-n:127.0.0.1:35791_solr) [n:127.0.0.1:35791_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Expecting [addreplicatest_coll_shard1_replica_n1, addreplicatest_coll_shard2_replica_n2] cores but found {}
[junit4] 2> 984851 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/addreplicatest_coll/state.json version: 0
[junit4] 2> 984852 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984852 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984955 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=addreplicatest_coll_shard1_replica_n1&action=CREATE&numShards=2&collection=addreplicatest_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 984955 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=addreplicatest_coll_shard2_replica_n2&action=CREATE&numShards=2&collection=addreplicatest_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 984955 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 984955 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 984961 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 984961 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 984961 DEBUG (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 984962 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984962 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984962 DEBUG (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController Registering watch for collection addreplicatest_coll
[junit4] 2> 984962 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 984962 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "node_name":"127.0.0.1:33253_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 984962 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "node_name":"127.0.0.1:33253_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 984962 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{"core":"addreplicatest_coll_shard1_replica_n1","base_url":"http://127.0.0.1:33253/solr","node_name":"127.0.0.1:33253_solr","state":"down","type":"NRT"}
[junit4] 2> 984962 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(addreplicatest_coll//collections/addreplicatest_coll/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "node_name":"127.0.0.1:33253_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 984964 DEBUG (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController waiting to find shard id in clusterstate for addreplicatest_coll_shard1_replica_n1
[junit4] 2> 984964 DEBUG (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController publishing state=down
[junit4] 2> 984965 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 984965 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 984965 DEBUG (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController Registering watch for collection addreplicatest_coll
[junit4] 2> 984965 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 984965 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "node_name":"127.0.0.1:36249_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 984965 DEBUG (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController waiting to find shard id in clusterstate for addreplicatest_coll_shard2_replica_n2
[junit4] 2> 984965 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=2 message={
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "node_name":"127.0.0.1:36249_solr",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"addreplicatest_coll",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 984965 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node4:{"core":"addreplicatest_coll_shard2_replica_n2","base_url":"http://127.0.0.1:36249/solr","node_name":"127.0.0.1:36249_solr","state":"down","type":"NRT"}
[junit4] 2> 984966 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(addreplicatest_coll//collections/addreplicatest_coll/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"addreplicatest_coll_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:33253/solr",
[junit4] 2> "node_name":"127.0.0.1:33253_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node4":{
[junit4] 2> "core":"addreplicatest_coll_shard2_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:36249/solr",
[junit4] 2> "node_name":"127.0.0.1:36249_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 984976 DEBUG (ScheduledTrigger-3657-thread-3) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 985066 DEBUG (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/addreplicatest_coll/state.json version: 1
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985067 INFO (zkCallback-2391-thread-1-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addreplicatest_coll/state.json] for collection [addreplicatest_coll] has occurred - updating... (live nodes size: [4])
[junit4] 2> 985067 INFO (zkCallback-2395-thread-1-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addreplicatest_coll/state.json] for collection [addreplicatest_coll] has occurred - updating... (live nodes size: [4])
[junit4] 2> 985067 INFO (zkCallback-2391-thread-2-processing-n:127.0.0.1:36249_solr) [n:127.0.0.1:36249_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addreplicatest_coll/state.json] for collection [addreplicatest_coll] has occurred - updating... (live nodes size: [4])
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985067 INFO (zkCallback-2395-thread-2-processing-n:127.0.0.1:33253_solr) [n:127.0.0.1:33253_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addreplicatest_coll/state.json] for collection [addreplicatest_coll] has occurred - updating... (live nodes size: [4])
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: children: /solr/overseer/queue
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985067 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: data: /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 985068 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: children: /solr/overseer/queue
[junit4] 2> 985975 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 985975 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 985987 DEBUG (ScheduledTrigger-3657-thread-2) [n:127.0.0.1:35791_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 985994 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.IndexSchema [addreplicatest_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 985994 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.IndexSchema [addreplicatest_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 985997 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 985997 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'addreplicatest_coll_shard2_replica_n2' using configuration from collection addreplicatest_coll, trusted=true
[junit4] 2> 985997 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 985997 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'addreplicatest_coll_shard1_replica_n1' using configuration from collection addreplicatest_coll, trusted=true
[junit4] 2> 985998 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36249.solr.core.addreplicatest_coll.shard2.replica_n2' (registry 'solr.core.addreplicatest_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 985998 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33253.solr.core.addreplicatest_coll.shard1.replica_n1' (registry 'solr.core.addreplicatest_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b0e39e
[junit4] 2> 985998 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 985998 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 985998 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore [[addreplicatest_coll_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node2/addreplicatest_coll_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node2/./addreplicatest_coll_shard2_replica_n2/data/]
[junit4] 2> 985998 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore [[addreplicatest_coll_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node3/addreplicatest_coll_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001/tempDir-001/node3/./addreplicatest_coll_shard1_replica_n1/data/]
[junit4] 2> 986056 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 986056 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 986057 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 986057 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 986058 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 986058 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 986075 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 986075 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 986077 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2cf8d0[addreplicatest_coll_shard1_replica_n1] main]
[junit4] 2> 986077 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d88d6b[addreplicatest_coll_shard2_replica_n2] main]
[junit4] 2> 986078 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 986078 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 986078 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 986078 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 986079 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 986079 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 986080 INFO (searcherExecutor-3669-thread-1-processing-n:127.0.0.1:33253_solr x:addreplicatest_coll_shard1_replica_n1 s:shard1 c:addreplicatest_coll r:core_node3) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.SolrCore [addreplicatest_coll_shard1_replica_n1] Registered new searcher Searcher@2cf8d0[addreplicatest_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 986080 INFO (searcherExecutor-3668-thread-1-processing-n:127.0.0.1:36249_solr x:addreplicatest_coll_shard2_replica_n2 s:shard2 c:addreplicatest_coll r:core_node4) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.SolrCore [addreplicatest_coll_shard2_replica_n2] Registered new searcher Searcher@1d88d6b[addreplicatest_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 986080 INFO (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1595783568881090560
[junit4] 2> 986080 INFO (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1595783568881090560
[junit4] 2> 986081 DEBUG (qtp956222-9846) [n:127.0.0.1:33253_solr c:addreplicatest_coll s:shard1 r:core_node3 x:addreplicatest_coll_shard1_replica_n1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 986081 DEBUG (qtp19268575-9718) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 986081 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/configs/conf1
[junit4] 2> 986081 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/configs/conf1
[junit4] 2> 986083 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard1
[junit4] 2> 986083 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch added: create/delete: /solr/collections/addreplicatest_coll/terms/shard2
[junit4] 2> 9860
[...truncated too long message...]
ontroller No more listeners for config directory [/configs/conf1]
[junit4] 2> 990842 INFO (jetty-closer-2362-thread-3) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 990843 DEBUG (SyncThread:0) [ ] o.a.s.c.ZkTestServer Watch fired: create/delete: /solr/collections/addreplicatest_coll/leader_elect/shard1/election/72188364885852172-core_node3-n_0000000000
[junit4] 2> 990844 INFO (jetty-closer-2362-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@858f34{/solr,null,UNAVAILABLE}
[junit4] 2> 990844 INFO (jetty-closer-2362-thread-1) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 990846 INFO (coreCloseExecutor-3685-thread-1) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.addreplicatest_coll.shard2.leader, tag=26127885
[junit4] 2> 990846 DEBUG (coreCloseExecutor-3685-thread-1) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController removed listener for config directory [/configs/conf1]
[junit4] 2> 990846 DEBUG (coreCloseExecutor-3685-thread-1) [n:127.0.0.1:36249_solr c:addreplicatest_coll s:shard2 r:core_node4 x:addreplicatest_coll_shard2_replica_n2] o.a.s.c.ZkController No more listeners for config directory [/configs/conf1]
[junit4] 2> 990850 INFO (jetty-closer-2362-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3cf78a{/solr,null,UNAVAILABLE}
[junit4] 2> 990850 INFO (jetty-closer-2362-thread-2) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 990854 INFO (coreCloseExecutor-3686-thread-1) [n:127.0.0.1:35791_solr c:addreplicatest_coll s:shard1 r:core_node6 x:addreplicatest_coll_shard1_replica_n5] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.addreplicatest_coll.shard1.leader, tag=23377636
[junit4] 2> 990854 DEBUG (coreCloseExecutor-3686-thread-1) [n:127.0.0.1:35791_solr c:addreplicatest_coll s:shard1 r:core_node6 x:addreplicatest_coll_shard1_replica_n5] o.a.s.c.ZkController removed listener for config directory [/configs/conf1]
[junit4] 2> 990854 DEBUG (coreCloseExecutor-3686-thread-1) [n:127.0.0.1:35791_solr c:addreplicatest_coll s:shard1 r:core_node6 x:addreplicatest_coll_shard1_replica_n5] o.a.s.c.ZkController No more listeners for config directory [/configs/conf1]
[junit4] 2> 990857 INFO (jetty-closer-2362-thread-4) [ ] o.a.s.c.Overseer Overseer (id=72188364885852171-127.0.0.1:35791_solr-n_0000000000) closing
[junit4] 2> 990857 INFO (OverseerStateUpdate-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35791_solr
[junit4] 2> 990857 WARN (OverseerAutoScalingTriggerThread-72188364885852171-127.0.0.1:35791_solr-n_0000000000) [n:127.0.0.1:35791_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 990858 DEBUG (jetty-closer-2362-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 990859 INFO (jetty-closer-2362-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@11c1a54{/solr,null,UNAVAILABLE}
[junit4] 2> 990859 INFO (jetty-closer-2362-thread-4) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 990859 ERROR (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-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> 990860 INFO (SUITE-AddReplicaTest-seed#[627E21DB037B0634]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:35393 35393
[junit4] 2> 991738 INFO (Thread-2367) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:35393 35393
[junit4] 2> 991739 WARN (Thread-2367) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/aliases.json
[junit4] 2> 9 /solr/collections/addreplicatest_coll/terms/shard1
[junit4] 2> 9 /solr/clusterprops.json
[junit4] 2> 4 /solr/security.json
[junit4] 2> 3 /solr/configs/conf1
[junit4] 2> 2 /solr/collections/addreplicatest_coll/terms/shard2
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 23 /solr/collections/addreplicatest_coll/state.json
[junit4] 2> 9 /solr/clusterstate.json
[junit4] 2> 2 /solr/overseer_elect/election/72188364885852170-127.0.0.1:36249_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/live_nodes
[junit4] 2> 9 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.AddReplicaTest_627E21DB037B0634-001
[junit4] 2> Mar 24, 2018 2:16:49 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=Lucene70, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1893785), locale=ru-RU, timezone=Pacific/Kiritimati
[junit4] 2> NOTE: Linux 4.13.0-36-generic i386/Oracle Corporation 1.8.0_162 (32-bit)/cpus=8,threads=1,free=140591568,total=337100800
[junit4] 2> NOTE: All tests run in this JVM: [BasicAuthStandaloneTest, TestSortByMinMaxFunction, PropertiesRequestHandlerTest, OverseerRolesTest, AnalysisAfterCoreReloadTest, TestLFUCache, TestCollationFieldDocValues, CircularListTest, TestDistributedMap, ConcurrentCreateRoutedAliasTest, TestNodeLostTrigger, TestCoreDiscovery, TestNumericTerms64, NotRequiredUniqueKeyTest, HdfsRecoveryZkTest, TestBadConfig, TermVectorComponentTest, DeleteLastCustomShardedReplicaTest, TestSchemaNameResource, TestFieldCacheWithThreads, URLClassifyProcessorTest, TestSubQueryTransformerDistrib, TolerantUpdateProcessorTest, SortSpecParsingTest, HdfsWriteToMultipleCollectionsTest, TestFiltering, DateMathParserTest, SuggesterTSTTest, CdcrBootstrapTest, TestCryptoKeys, TestChildDocTransformer, SolrCmdDistributorTest, ClusterStateTest, TestSmileRequest, ConjunctionSolrSpellCheckerTest, AutoScalingHandlerTest, ClassificationUpdateProcessorFactoryTest, TestQuerySenderListener, SpellCheckComponentTest, TestRawTransformer, TestBlendedInfixSuggestions, StatsReloadRaceTest, AsyncCallRequestStatusResponseTest, TestNonDefinedSimilarityFactory, DateFieldTest, WordBreakSolrSpellCheckerTest, AnalyticsQueryTest, LeaderElectionTest, AnalysisErrorHandlingTest, TestDFRSimilarityFactory, DirectSolrSpellCheckerTest, SimpleMLTQParserTest, TestSchemaManager, BlockJoinFacetRandomTest, DistributedFacetSimpleRefinementLongTailTest, TestExportWriter, SpatialFilterTest, TestLockTree, DocValuesTest, PreAnalyzedFieldTest, TestSolrFieldCacheBean, SimpleCollectionCreateDeleteTest, TestPolicyCloud, TestJsonFacetsWithNestedObjects, TestInPlaceUpdatesStandalone, TestReloadDeadlock, UnloadDistributedZkTest, SaslZkACLProviderTest, TestStressReorder, TestPayloadScoreQParserPlugin, TestSolrCoreSnapshots, JvmMetricsTest, OverriddenZkACLAndCredentialsProvidersTest, TestFieldResource, TestCloudJSONFacetJoinDomain, SolrMetricManagerTest, TestRequestStatusCollectionAPI, SolrCloudExampleTest, RuleEngineTest, TestGenericDistributedQueue, SmileWriterTest, TestLegacyTerms, DistributedDebugComponentTest, ScheduledTriggerTest, SolrGangliaReporterTest, AutoscalingHistoryHandlerTest, CustomCollectionTest, ReturnFieldsTest, SolrTestCaseJ4Test, UtilsToolTest, TestHighFrequencyDictionaryFactory, PeerSyncWithIndexFingerprintCachingTest, TestStressCloudBlindAtomicUpdates, SolrShardReporterTest, TestSolrConfigHandler, NumericFieldsTest, TestSuggestSpellingConverter, TestRequestForwarding, HdfsThreadLeakTest, MoveReplicaHDFSFailoverTest, LeaderFailoverAfterPartitionTest, CopyFieldTest, ClusterStateUpdateTest, TestShortCircuitedRequests, TestSolrCloudWithDelegationTokens, LargeFieldTest, TestQueryTypes, TestZkAclsWithHadoopAuth, TestAnalyzedSuggestions, TestRestManager, InfixSuggestersTest, TestPrepRecovery, TestCoreBackup, TestJettySolrRunner, ParsingFieldUpdateProcessorsTest, TestExactStatsCache, StatelessScriptUpdateProcessorFactoryTest, TestTrieFacet, HdfsChaosMonkeySafeLeaderTest, TestScoreJoinQPScore, BasicDistributedZk2Test, MoreLikeThisHandlerTest, AddReplicaTest]
[junit4] Completed [315/785 (1!)] on J2 in 12.43s, 1 test, 1 failure <<< FAILURES!
[...truncated 46733 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21690/consoleText
[repro] Revision: ea504091e517b5a2941b76adef7270b3d6ecb34c
[repro] Ant options: "-Dargs=-client -XX:+UseSerialGC"
[repro] Repro line: ant test -Dtestcase=AddReplicaTest -Dtests.method=test -Dtests.seed=627E21DB037B0634 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ru-RU -Dtests.timezone=Pacific/Kiritimati -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] AddReplicaTest
[repro] ant compile-test
[...truncated 3296 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.AddReplicaTest" -Dtests.showOutput=onerror "-Dargs=-client -XX:+UseSerialGC" -Dtests.seed=627E21DB037B0634 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ru-RU -Dtests.timezone=Pacific/Kiritimati -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 71 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.AddReplicaTest
[repro] Exiting with code 0
[...truncated 40 lines...]
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk-9.0.4) - Build #
21691 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21691/
Java: 64bit/jdk-9.0.4 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.search.TestStressRecovery.testStressRecovery
Error Message:
Captured an uncaught exception in thread: Thread[id=244, name=READER7, state=RUNNABLE, group=TGRP-TestStressRecovery]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=244, name=READER7, state=RUNNABLE, group=TGRP-TestStressRecovery]
at __randomizedtesting.SeedInfo.seed([480CD2B01ED69D4F:F236BBED813E2241]:0)
Caused by: java.lang.RuntimeException: java.lang.NullPointerException
at __randomizedtesting.SeedInfo.seed([480CD2B01ED69D4F]:0)
at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:332)
Caused by: java.lang.NullPointerException
at org.apache.solr.update.TransactionLog$FSReverseReader.<init>(TransactionLog.java:807)
at org.apache.solr.update.TransactionLog.getReverseReader(TransactionLog.java:645)
at org.apache.solr.update.UpdateLog$RecentUpdates.update(UpdateLog.java:1405)
at org.apache.solr.update.UpdateLog$RecentUpdates.<init>(UpdateLog.java:1340)
at org.apache.solr.update.UpdateLog.getRecentUpdates(UpdateLog.java:1516)
at org.apache.solr.search.TestRTGBase.getLatestVersions(TestRTGBase.java:103)
at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:326)
Build Log:
[...truncated 1853 lines...]
[junit4] JVM J0: stdout was not empty, see: /home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/core/test/temp/junit4-J0-20180324_083118_9708122967356957003722.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: CheapBastard, pf: LuceneFixedGap, dvf: Asserting
[junit4] <<< JVM J0: EOF ----
[...truncated 10271 lines...]
[junit4] Suite: org.apache.solr.search.TestStressRecovery
[junit4] 2> 22264 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.search.TestStressRecovery_480CD2B01ED69D4F-001/init-core-data-001
[junit4] 2> 22265 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 22266 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 22267 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 updateLog impl=solr.CdcrUpdateLog
[junit4] 2> 22267 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 22268 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 22297 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 22351 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 22357 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.TrieIntField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22359 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.TrieFloatField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22360 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.TrieLongField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22364 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.CurrencyField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22373 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.TrieDateField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22456 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.GeoHashField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22459 WARN (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.LatLonType]. Please consult documentation how to replace it accordingly.
[junit4] 2> 22473 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 22546 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@16151592
[junit4] 2> 22546 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@16151592
[junit4] 2> 22546 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@16151592
[junit4] 2> 22550 INFO (coreLoadExecutor-18-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 22551 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 22567 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 22582 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 22655 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 22677 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 22678 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@16151592
[junit4] 2> 22678 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 22678 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.search.TestStressRecovery_480CD2B01ED69D4F-001/init-core-data-001/]
[junit4] 2> 22682 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=69.572265625, floorSegmentMB=1.48828125, forceMergeDeletesPctAllowed=6.326865520847665, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 22705 WARN (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 22755 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 22756 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 22762 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 22762 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 22763 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=99.58203125, floorSegmentMB=0.306640625, forceMergeDeletesPctAllowed=4.848226399052551, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.810992598668766
[junit4] 2> 22764 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3327dfd5[collection1] main]
[junit4] 2> 22765 WARN (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf; switching to use InMemory storage instead.
[junit4] 2> 22767 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 22770 INFO (searcherExecutor-19-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3327dfd5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 22771 INFO (coreLoadExecutor-18-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1595808735956041728
[junit4] 2> 22776 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 22778 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStressRecovery
[junit4] 2> 22779 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 22780 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@22c74735[collection1] realtime]
[junit4] 2> 22780 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 22780 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1595808735965478912,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 22780 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7b2f6757 commitCommandVersion:1595808735965478912
[junit4] 2> 22782 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@56fbb087[collection1] main]
[junit4] 2> 22782 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 22791 INFO (searcherExecutor-19-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@56fbb087[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 22791 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 11
[junit4] 2> 22800 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 22801 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=2
[junit4] 2> 22801 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22801 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=2
[junit4] 2> 22802 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:34&omitHeader=true&wt=json} hits=0 status=0 QTime=3
[junit4] 2> 22802 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:20&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22803 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22803 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:4&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22803 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22805 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=1
[junit4] 2> 22805 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22810 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=8
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=69&wt=json} status=0 QTime=8
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=35&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22810 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:76&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22810 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=4
[junit4] 2> 22810 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=9
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=65&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=32&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:85&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=10
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:67&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=103&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=50&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:86&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:63&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:96&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=50&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:11&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=96&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=33&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:18&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22812 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-2&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[0 (-2)]} 0 13
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=11
[junit4] 2> 22812 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=9
[junit4] 2> 22812 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=11
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:88&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22810 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=8
[junit4] 2> 22810 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-1&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[0 (-1)]} 0 10
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:57&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=34&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 22812 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22814 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=53&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=9&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=39&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=56&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=49&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=102&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22811 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22811 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22814 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=98&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:32&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=56&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:6&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=87&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:22&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:102&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:22&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22815 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 22815 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:58&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=57&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:86&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:11&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=82&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=104&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22816 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 22816 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:68&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:3&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=82&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:43&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:81&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:70&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=3&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=55&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=103&wt=json} status=0 QTime=0
[junit4] 2> 22817 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22817 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=101&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=6&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:104&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=76&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:5&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:55&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22810 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.search.TestStressRecovery_480CD2B01ED69D4F-001/init-core-data-001/tlog/tlog.0000000000000000001.2 refcount=4}}
[junit4] 2> 22816 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=69&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=88&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 22818 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=35&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=68&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (WRITER0) [ ] o.a.s.u.p.DistributedUpdateProcessor Ignoring commit while not ACTIVE - state: BUFFERING replay: false
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22819 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:98&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=94&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=89&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:65&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22819 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 22819 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:67&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:57&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:24&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=87&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:97&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22820 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=80&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:33&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=75&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=103&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:89&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=82&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=97&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=39&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:96&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=46&wt=json} status=0 QTime=0
[junit4] 2> 22814 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:0&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22813 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 22813 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=28&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:27&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:88&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=27&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=81&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:57&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:26&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=11&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 22822 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:9&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:50&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=48&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:21&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:1&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=81&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:80&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22821 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:27&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:83&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:51&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=23&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:87&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:41&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=78&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=68&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=52&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:100&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:74&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22824 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:85&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:24&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=54&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=64&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=18&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:13&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22825 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=7&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22821 INFO (WRITER1) [ ] o.a.s.u.p.DistributedUpdateProcessor Ignoring commit while not ACTIVE - state: BUFFERING replay: false
[junit4] 2> 22821 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-3&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[38 (-3)]} 0 0
[junit4] 2> 22825 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 22821 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=16&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:101&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22825 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=49&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=5&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=41&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=52&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=77&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=12&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=66&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=22&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=35&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=32&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=95&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=24&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-4&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[38 (-4)]} 0 0
[junit4] 2> 22826 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:38&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:57&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22818 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22826 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-5&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[38 (-5)]} 0 0
[junit4] 2> 22826 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 22825 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:17&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22827 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=61&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:103&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22827 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=72&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=85&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=70&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22824 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:100&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22823 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:69&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:27&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22827 INFO (WRITER1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-6&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{delete=[44 (-6)]} 0 0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22827 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=42&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=34&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=17&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:92&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:92&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:81&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=2&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:30&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:97&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=4&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22828 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=67&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=15&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=0&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:97&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:33&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22823 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:66&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22822 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=38&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=37&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=14&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=86&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=100&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=1&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=99&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=82&wt=json} status=0 QTime=0
[junit4] 2> 22827 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:75&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22829 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:76&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:2&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22829 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:63&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:81&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:60&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=30&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:42&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=74&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=51&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=73&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:76&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:8&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=25&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:21&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=42&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:15&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=98&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:44&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:104&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22830 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=83&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=29&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=58&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=57&wt=json} status=0 QTime=0
[junit4] 2> 22830 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=47&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:20&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 22831 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=26&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=96&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=44&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=59&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=19&wt=json} status=0 QTime=0
[junit4] 2> 22831 INFO
[...truncated too long message...]
e=[4 (-1696)]} 0 5
[junit4] 2> 29107 INFO (WRITER0) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1595808742594576384,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 29107 INFO (WRITER0) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7b2f6757 commitCommandVersion:1595808742594576384
[junit4] 2> 29102 INFO (READER4) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=93&wt=json} status=0 QTime=0
[junit4] 2> 29102 INFO (READER3) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=21&wt=json} status=0 QTime=0
[junit4] 2> 29105 INFO (READER7) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=20&wt=json} status=0 QTime=0
[junit4] 2> 29103 INFO (READER5) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:4&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 29103 INFO (READER6) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:12&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 29103 INFO (READER0) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=64&wt=json} status=0 QTime=0
[junit4] 2> 29110 INFO (WRITER0) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@64580d6e[collection1] main]
[junit4] 2> 29103 INFO (READER8) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:8&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 29103 INFO (READER1) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&ids=71&wt=json} status=0 QTime=0
[junit4] 2> 29102 INFO (READER2) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:4&omitHeader=true&wt=json} hits=0 status=0 QTime=0
[junit4] 2> 29115 INFO (searcherExecutor-19-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@64580d6e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 29115 INFO (WRITER0) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 29115 INFO (WRITER0) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 12
[junit4] 2> ŋ3 24, 2018 11:56:51 SÁRÚWÁ com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
[junit4] 2> WARNING: Uncaught exception in thread: Thread[READER7,5,TGRP-TestStressRecovery]
[junit4] 2> java.lang.RuntimeException: java.lang.NullPointerException
[junit4] 2> at __randomizedtesting.SeedInfo.seed([480CD2B01ED69D4F]:0)
[junit4] 2> at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:332)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.solr.update.TransactionLog$FSReverseReader.<init>(TransactionLog.java:807)
[junit4] 2> at org.apache.solr.update.TransactionLog.getReverseReader(TransactionLog.java:645)
[junit4] 2> at org.apache.solr.update.UpdateLog$RecentUpdates.update(UpdateLog.java:1405)
[junit4] 2> at org.apache.solr.update.UpdateLog$RecentUpdates.<init>(UpdateLog.java:1340)
[junit4] 2> at org.apache.solr.update.UpdateLog.getRecentUpdates(UpdateLog.java:1516)
[junit4] 2> at org.apache.solr.search.TestRTGBase.getLatestVersions(TestRTGBase.java:103)
[junit4] 2> at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:326)
[junit4] 2>
[junit4] 2> 29118 INFO (TEST-TestStressRecovery.testStressRecovery-seed#[480CD2B01ED69D4F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStressRecovery
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestStressRecovery -Dtests.method=testStressRecovery -Dtests.seed=480CD2B01ED69D4F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ksf -Dtests.timezone=Europe/Simferopol -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 6.34s J1 | TestStressRecovery.testStressRecovery <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=244, name=READER7, state=RUNNABLE, group=TGRP-TestStressRecovery]
[junit4] > at __randomizedtesting.SeedInfo.seed([480CD2B01ED69D4F:F236BBED813E2241]:0)
[junit4] > Caused by: java.lang.RuntimeException: java.lang.NullPointerException
[junit4] > at __randomizedtesting.SeedInfo.seed([480CD2B01ED69D4F]:0)
[junit4] > at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:332)
[junit4] > Caused by: java.lang.NullPointerException
[junit4] > at org.apache.solr.update.TransactionLog$FSReverseReader.<init>(TransactionLog.java:807)
[junit4] > at org.apache.solr.update.TransactionLog.getReverseReader(TransactionLog.java:645)
[junit4] > at org.apache.solr.update.UpdateLog$RecentUpdates.update(UpdateLog.java:1405)
[junit4] > at org.apache.solr.update.UpdateLog$RecentUpdates.<init>(UpdateLog.java:1340)
[junit4] > at org.apache.solr.update.UpdateLog.getRecentUpdates(UpdateLog.java:1516)
[junit4] > at org.apache.solr.search.TestRTGBase.getLatestVersions(TestRTGBase.java:103)
[junit4] > at org.apache.solr.search.TestStressRecovery$2.run(TestStressRecovery.java:326)
[junit4] 2> 29120 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 29120 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1547388301
[junit4] 2> 29120 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 29121 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@171354ab: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@493c61f5
[junit4] 2> 29125 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 29125 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@77e072ac: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@3f89e4df
[junit4] 2> 29125 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 29125 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6a45d988: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@c3d1d6c
[junit4] 2> 29126 INFO (coreCloseExecutor-24-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5c980f88
[junit4] 2> 29126 INFO (coreCloseExecutor-24-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1553469320
[junit4] 2> 29126 INFO (coreCloseExecutor-24-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@42b4db21: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@14e10765
[junit4] 2> 29135 INFO (SUITE-TestStressRecovery-seed#[480CD2B01ED69D4F]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7cd76edf), locale=ksf, timezone=Europe/Simferopol
[junit4] 2> NOTE: Linux 4.13.0-36-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=328186000,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestSolr4Spatial, HdfsLockFactoryTest, TestStressRecovery]
[junit4] Completed [8/785 (1!)] on J1 in 6.89s, 1 test, 1 error <<< FAILURES!
[...truncated 45397 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21691/consoleText
[repro] Revision: ea504091e517b5a2941b76adef7270b3d6ecb34c
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestStressRecovery -Dtests.method=testStressRecovery -Dtests.seed=480CD2B01ED69D4F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ksf -Dtests.timezone=Europe/Simferopol -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestStressRecovery
[repro] ant compile-test
[...truncated 3301 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestStressRecovery" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=480CD2B01ED69D4F -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ksf -Dtests.timezone=Europe/Simferopol -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 76 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.search.TestStressRecovery
[repro] Exiting with code 0
[...truncated 40 lines...]