You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2019/03/03 14:56:25 UTC

[JENKINS] Lucene-Solr-NightlyTests-master - Build # 1782 - Still unstable

Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1782/

1 tests failed.
FAILED:  org.apache.solr.cloud.LeaderTragicEventTest.test

Error Message:
Failed while waiting for active collection Timeout waiting to see state for collection=collection1 :null Live Nodes: [127.0.0.1:42645_solr, 127.0.0.1:44663_solr] Last available state: null

Stack Trace:
java.lang.RuntimeException: Failed while waiting for active collection
Timeout waiting to see state for collection=collection1 :null
Live Nodes: [127.0.0.1:42645_solr, 127.0.0.1:44663_solr]
Last available state: null
	at __randomizedtesting.SeedInfo.seed([B08E06BACFF4A41:835CDFB1020327B9]:0)
	at org.apache.solr.cloud.MiniSolrCloudCluster.waitForActiveCollection(MiniSolrCloudCluster.java:728)
	at org.apache.solr.cloud.MiniSolrCloudCluster.waitForActiveCollection(MiniSolrCloudCluster.java:734)
	at org.apache.solr.cloud.LeaderTragicEventTest.test(LeaderTragicEventTest.java:80)
	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:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	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:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	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 14637 lines...]
   [junit4] Suite: org.apache.solr.cloud.LeaderTragicEventTest
   [junit4]   2> 2331549 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/init-core-data-001
   [junit4]   2> 2331550 WARN  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=28 numCloses=28
   [junit4]   2> 2331550 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 2331552 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-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> 2331553 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001
   [junit4]   2> 2331553 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2331554 INFO  (ZkTestServer Run Thread) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2331554 INFO  (ZkTestServer Run Thread) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 2331654 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:34053
   [junit4]   2> 2331654 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:34053
   [junit4]   2> 2331654 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 34053
   [junit4]   2> 2331672 INFO  (zkConnectionManagerCallback-10210-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331677 INFO  (zkConnectionManagerCallback-10212-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331678 INFO  (zkConnectionManagerCallback-10214-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331685 WARN  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 2331685 WARN  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 2331686 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 2331687 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2331687 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2331687 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 2331687 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7efbabd2{/solr,null,AVAILABLE}
   [junit4]   2> 2331688 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2331688 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2331688 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 2331688 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@10d11f5d{/solr,null,AVAILABLE}
   [junit4]   2> 2331689 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@26dd690c{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44663}
   [junit4]   2> 2331689 INFO  (jetty-launcher-10215-thread-1) [    ] o.e.j.s.Server Started @2331744ms
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@768a36d8{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:42645}
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.e.j.s.Server Started @2331745ms
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42645}
   [junit4]   2> 2331690 ERROR (jetty-launcher-10215-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 9.0.0
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2331690 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-03-03T13:47:28.804Z
   [junit4]   2> 2331689 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44663}
   [junit4]   2> 2331692 ERROR (jetty-launcher-10215-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2331692 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2331692 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 9.0.0
   [junit4]   2> 2331692 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2331692 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2331692 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-03-03T13:47:28.806Z
   [junit4]   2> 2331695 INFO  (zkConnectionManagerCallback-10217-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331695 INFO  (zkConnectionManagerCallback-10219-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331696 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2331700 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2331877 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 2331878 WARN  (jetty-launcher-10215-thread-2) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6cf360c9[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2331883 WARN  (jetty-launcher-10215-thread-2) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@d511209[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2331884 INFO  (jetty-launcher-10215-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34053/solr
   [junit4]   2> 2331885 INFO  (zkConnectionManagerCallback-10225-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331886 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 2331888 WARN  (jetty-launcher-10215-thread-1) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@2e954d4[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2331891 INFO  (zkConnectionManagerCallback-10228-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331899 WARN  (jetty-launcher-10215-thread-1) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@3ddf297[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2331902 INFO  (jetty-launcher-10215-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34053/solr
   [junit4]   2> 2331904 INFO  (zkConnectionManagerCallback-10235-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331906 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x102f84b1cb70007, likely client has closed socket
   [junit4]   2> 2331907 INFO  (zkConnectionManagerCallback-10237-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331921 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44663_solr
   [junit4]   2> 2331922 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.c.Overseer Overseer (id=72893545479340040-127.0.0.1:44663_solr-n_0000000000) starting
   [junit4]   2> 2331931 INFO  (zkConnectionManagerCallback-10244-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2331935 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34053/solr ready
   [junit4]   2> 2331937 INFO  (OverseerStateUpdate-72893545479340040-127.0.0.1:44663_solr-n_0000000000) [n:127.0.0.1:44663_solr    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:44663_solr
   [junit4]   2> 2331938 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44663_solr
   [junit4]   2> 2331941 INFO  (zkCallback-10243-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2331941 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2331985 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 2331988 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2331992 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.ZkController Publish node=127.0.0.1:42645_solr as DOWN
   [junit4]   2> 2331993 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 2331993 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42645_solr
   [junit4]   2> 2331994 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2331998 INFO  (zkCallback-10243-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2332002 INFO  (zkCallback-10227-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2332022 INFO  (zkConnectionManagerCallback-10250-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2332023 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2332025 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34053/solr ready
   [junit4]   2> 2332025 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 2332029 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44663.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332045 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44663.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332045 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44663.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332046 INFO  (jetty-launcher-10215-thread-1) [n:127.0.0.1:44663_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node1/.
   [junit4]   2> 2332052 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42645.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332065 WARN  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.m.r.j.JmxMetricsReporter Unable to register gauge
   [junit4]   2>           => javax.management.InstanceNotFoundException: solr_42645:dom1=solr,dom2=jvm,name0=os,name=availableProcessors
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1095)
   [junit4]   2> javax.management.InstanceNotFoundException: solr_42645:dom1=solr,dom2=jvm,name0=os,name=availableProcessors
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1095) ~[?:1.8.0_191]
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:427) ~[?:1.8.0_191]
   [junit4]   2> 	at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415) ~[?:1.8.0_191]
   [junit4]   2> 	at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546) ~[?:1.8.0_191]
   [junit4]   2> 	at org.apache.solr.metrics.reporters.jmx.JmxMetricsReporter$JmxListener.registerMBean(JmxMetricsReporter.java:531) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.reporters.jmx.JmxMetricsReporter$JmxListener.onGaugeAdded(JmxMetricsReporter.java:569) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.reporters.jmx.JmxMetricsReporter.lambda$start$0(JmxMetricsReporter.java:742) ~[java/:?]
   [junit4]   2> 	at java.util.HashMap.forEach(HashMap.java:1289) ~[?:1.8.0_191]
   [junit4]   2> 	at org.apache.solr.metrics.reporters.jmx.JmxMetricsReporter.start(JmxMetricsReporter.java:732) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.reporters.SolrJmxReporter.doInit(SolrJmxReporter.java:110) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.SolrMetricReporter.init(SolrMetricReporter.java:70) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.SolrMetricManager.loadReporter(SolrMetricManager.java:916) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.metrics.SolrMetricManager.loadReporters(SolrMetricManager.java:843) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.core.CoreContainer.load(CoreContainer.java:601) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.createCoreContainer(SolrDispatchFilter.java:252) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:172) ~[java/:?]
   [junit4]   2> 	at org.eclipse.jetty.servlet.FilterHolder.initialize(FilterHolder.java:136) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.lambda$initialize$0(ServletHandler.java:750) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:948) ~[?:1.8.0_191]
   [junit4]   2> 	at java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:742) ~[?:1.8.0_191]
   [junit4]   2> 	at java.util.stream.Streams$ConcatSpliterator.forEachRemaining(Streams.java:742) ~[?:1.8.0_191]
   [junit4]   2> 	at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:580) ~[?:1.8.0_191]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:744) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.updateMappings(ServletHandler.java:1449) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.setFilterMappings(ServletHandler.java:1513) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.addFilterMapping(ServletHandler.java:1158) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.addFilterWithMapping(ServletHandler.java:995) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletContextHandler.addFilter(ServletContextHandler.java:467) ~[jetty-servlet-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$1.lifeCycleStarted(JettySolrRunner.java:381) ~[java/:?]
   [junit4]   2> 	at org.eclipse.jetty.util.component.AbstractLifeCycle.setStarted(AbstractLifeCycle.java:179) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:69) ~[jetty-util-9.4.14.v20181114.jar:9.4.14.v20181114]
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner.retryOnPortBindFailure(JettySolrRunner.java:544) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:483) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner.start(JettySolrRunner.java:451) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.MiniSolrCloudCluster.startJettySolrRunner(MiniSolrCloudCluster.java:437) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.MiniSolrCloudCluster.lambda$new$0(MiniSolrCloudCluster.java:272) ~[java/:?]
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_191]
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
   [junit4]   2> 2332073 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42645.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332073 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42645.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2332075 INFO  (jetty-launcher-10215-thread-2) [n:127.0.0.1:42645_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node2/.
   [junit4]   2> 2332131 INFO  (zkConnectionManagerCallback-10256-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2332133 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2332134 INFO  (SUITE-LeaderTragicEventTest-seed#[B08E06BACFF4A41]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34053/solr ready
   [junit4]   2> 2332164 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testOtherReplicasAreNotActive
   [junit4]   2> 2332166 INFO  (qtp392828755-37997) [n:127.0.0.1:42645_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=config&name=collection2&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 2332170 INFO  (OverseerThreadFactory-9189-thread-1-processing-n:127.0.0.1:44663_solr) [n:127.0.0.1:44663_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection2
   [junit4]   2> 2332283 INFO  (OverseerStateUpdate-72893545479340040-127.0.0.1:44663_solr-n_0000000000) [n:127.0.0.1:44663_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection2",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"collection2_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:44663/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 2332286 INFO  (OverseerStateUpdate-72893545479340040-127.0.0.1:44663_solr-n_0000000000) [n:127.0.0.1:44663_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection2",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"collection2_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:42645/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 2332490 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr    x:collection2_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=config&newCollection=true&name=collection2_shard1_replica_n2&action=CREATE&numShards=1&collection=collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 2332491 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr    x:collection2_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=config&newCollection=true&name=collection2_shard1_replica_n1&action=CREATE&numShards=1&collection=collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 2332491 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr    x:collection2_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 2333509 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 2333510 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 2333537 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.IndexSchema [collection2_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 2333540 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2333540 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'collection2_shard1_replica_n1' using configuration from collection collection2, trusted=true
   [junit4]   2> 2333541 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44663.solr.core.collection2.shard1.replica_n1' (registry 'solr.core.collection2.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2333541 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [[collection2_shard1_replica_n1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node1/collection2_shard1_replica_n1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node1/./collection2_shard1_replica_n1/data/]
   [junit4]   2> 2333547 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.s.IndexSchema [collection2_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 2333551 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 2333551 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'collection2_shard1_replica_n2' using configuration from collection collection2, trusted=true
   [junit4]   2> 2333552 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42645.solr.core.collection2.shard1.replica_n2' (registry 'solr.core.collection2.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@ce43115
   [junit4]   2> 2333552 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.SolrCore [[collection2_shard1_replica_n2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node2/collection2_shard1_replica_n2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderTragicEventTest_B08E06BACFF4A41-001/tempDir-001/node2/./collection2_shard1_replica_n2/data/]
   [junit4]   2> 2333613 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 2333613 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2333616 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2333616 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2333618 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1286787d[collection2_shard1_replica_n1] main]
   [junit4]   2> 2333619 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 2333619 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 2333620 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 2333620 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1626992385179254784
   [junit4]   2> 2333621 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 2333621 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2333623 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@1286787d[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2333624 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2333624 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2333626 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@9ca17c9[collection2_shard1_replica_n2] main]
   [junit4]   2> 2333627 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection2/terms/shard1 to Terms{values={core_node3=0}, version=0}
   [junit4]   2> 2333627 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection2/leaders/shard1
   [junit4]   2> 2333628 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 2333628 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 2333629 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 2333629 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1626992385188691968
   [junit4]   2> 2333633 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9998ms
   [junit4]   2> 2333634 INFO  (searcherExecutor-9199-thread-1-processing-n:127.0.0.1:42645_solr x:collection2_shard1_replica_n2 c:collection2 s:shard1 r:core_node4) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.SolrCore [collection2_shard1_replica_n2] Registered new searcher Searcher@9ca17c9[collection2_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2333637 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection2/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
   [junit4]   2> 2333637 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection2/leaders/shard1
   [junit4]   2> 2334134 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2334134 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2334134 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44663/solr/collection2_shard1_replica_n1/
   [junit4]   2> 2334135 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=collection2_shard1_replica_n1 url=http://127.0.0.1:44663/solr START replicas=[http://127.0.0.1:42645/solr/collection2_shard1_replica_n2/] nUpdates=100
   [junit4]   2> 2334135 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=collection2_shard1_replica_n1 url=http://127.0.0.1:44663/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 2334137 INFO  (qtp392828755-37996) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.S.Request [collection2_shard1_replica_n2]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 2334137 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 2334137 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 2334137 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection2/leaders/shard1/leader after winning as /collections/collection2/leader_elect/shard1/election/72893545479340040-core_node3-n_0000000000
   [junit4]   2> 2334139 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44663/solr/collection2_shard1_replica_n1/ shard1
   [junit4]   2> 2334241 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334242 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2334245 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=config&newCollection=true&name=collection2_shard1_replica_n1&action=CREATE&numShards=1&collection=collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1754
   [junit4]   2> 2334345 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334345 INFO  (zkCallback-10236-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334647 INFO  (qtp392828755-37999) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=config&newCollection=true&name=collection2_shard1_replica_n2&action=CREATE&numShards=1&collection=collection2&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2158
   [junit4]   2> 2334651 INFO  (qtp392828755-37997) [n:127.0.0.1:42645_solr    ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
   [junit4]   2> 2334744 INFO  (zkCallback-10227-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334744 INFO  (zkCallback-10227-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334745 INFO  (zkCallback-10236-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334745 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 2334745 INFO  (qtp392828755-37997) [n:127.0.0.1:42645_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=config&name=collection2&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2579
   [junit4]   2> 2334748 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.LeaderTragicEventTest Stop jetty node : http://127.0.0.1:42645/solr state:DocCollection(collection2//collections/collection2/state.json/6)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"collection2_shard1_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:44663/solr",
   [junit4]   2>           "node_name":"127.0.0.1:44663_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false",
   [junit4]   2>           "leader":"true"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"collection2_shard1_replica_n2",
   [junit4]   2>           "base_url":"http://127.0.0.1:42645/solr",
   [junit4]   2>           "node_name":"127.0.0.1:42645_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"}}}},
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"1",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0"}
   [junit4]   2> 2334749 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1235177089
   [junit4]   2> 2334750 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:42645_solr
   [junit4]   2> 2334750 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 2334750 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:42645_solr as DOWN
   [junit4]   2> 2334753 INFO  (coreCloseExecutor-9208-thread-1) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.c.SolrCore [collection2_shard1_replica_n2]  CLOSING SolrCore org.apache.solr.core.SolrCore@2d2dbd2f
   [junit4]   2> 2334753 INFO  (coreCloseExecutor-9208-thread-1) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection2.shard1.replica_n2, tag=2d2dbd2f
   [junit4]   2> 2334753 INFO  (coreCloseExecutor-9208-thread-1) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@46995db5: rootName = solr_42645, domain = solr.core.collection2.shard1.replica_n2, service url = null, agent id = null] for registry solr.core.collection2.shard1.replica_n2 / com.codahale.metrics.MetricRegistry@618570b2
   [junit4]   2> 2334767 INFO  (coreCloseExecutor-9208-thread-1) [n:127.0.0.1:42645_solr c:collection2 s:shard1 r:core_node4 x:collection2_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection2.shard1.leader, tag=2d2dbd2f
   [junit4]   2> 2334770 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 2334770 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7e660808: rootName = solr_42645, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@53980bc4
   [junit4]   2> 2334779 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 2334779 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@59437ae5: rootName = solr_42645, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7a6992d9
   [junit4]   2> 2334783 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 2334783 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5683c1ee: rootName = solr_42645, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@311c9001
   [junit4]   2> 2334783 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   2> 2334787 INFO  (zkCallback-10255-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 2334788 INFO  (zkCallback-10243-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 2334788 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 2334790 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@768a36d8{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
   [junit4]   2> 2334790 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@10d11f5d{/solr,null,UNAVAILABLE}
   [junit4]   2> 2334791 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2334854 INFO  (zkCallback-10255-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 2334854 INFO  (zkCallback-10255-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 2334855 INFO  (zkCallback-10236-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 2334855 INFO  (zkCallback-10236-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection2/state.json] for collection [collection2] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 2334856 INFO  (TEST-LeaderTragicEventTest.testOtherReplicasAreNotActive-seed#[B08E06BACFF4A41]) [    ] o.a.s.c.LeaderTragicEventTest Corrupt leader : core_node3:{"core":"collection2_shard1_replica_n1","base_url":"http://127.0.0.1:44663/solr","node_name":"127.0.0.1:44663_solr","state":"active","type":"NRT","force_set_state":"false","leader":"true"}
   [junit4]   2> 2334861 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection2/terms/shard1 to Terms{values={core_node3=1, core_node4=0}, version=2}
   [junit4]   2> 2334861 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1626992386479489024)]} 0 1
   [junit4]   2> 2334862 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386481586176,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334862 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386481586176
   [junit4]   2> 2334868 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@257ebb5d[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334870 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@257ebb5d[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334870 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334870 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 8
   [junit4]   2> 2334874 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1626992386492071936)]} 0 2
   [junit4]   2> 2334876 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386496266240,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334876 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386496266240
   [junit4]   2> 2334880 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@54c63221[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334880 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334881 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@54c63221[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334882 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 6
   [junit4]   2> 2334884 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1626992386503606272)]} 0 1
   [junit4]   2> 2334885 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386505703424,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334885 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386505703424
   [junit4]   2> 2334888 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@43fb5928[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334888 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334890 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@43fb5928[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334890 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 5
   [junit4]   2> 2334892 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[3 (1626992386511994880)]} 0 1
   [junit4]   2> 2334893 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386514092032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334893 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386514092032
   [junit4]   2> 2334898 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@37125b23[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334899 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334900 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@37125b23[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334901 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
   [junit4]   2> 2334904 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[4 (1626992386524577792)]} 0 1
   [junit4]   2> 2334904 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386525626368,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334904 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386525626368
   [junit4]   2> 2334912 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@26e1add5[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334913 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334914 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@26e1add5[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852020}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334914 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 10
   [junit4]   2> 2334917 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1626992386538209280)]} 0 0
   [junit4]   2> 2334918 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386540306432,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334918 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386540306432
   [junit4]   2> 2334921 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3de68857[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334921 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334923 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@3de68857[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852020}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852033}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334924 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 6
   [junit4]   2> 2334926 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[6 (1626992386548695040)]} 0 0
   [junit4]   2> 2334927 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386549743616,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334927 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386549743616
   [junit4]   2> 2334935 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@67e680b2[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334935 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334937 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@67e680b2[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852020}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852033}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852047}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334937 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 10
   [junit4]   2> 2334940 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[7 (1626992386562326528)]} 0 1
   [junit4]   2> 2334941 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386564423680,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334941 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386564423680
   [junit4]   2> 2334944 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3eee180[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334944 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334946 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@3eee180[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852020}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852033}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852047}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_7(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852056}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334946 INFO  (qtp1341645024-37992) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 5
   [junit4]   2> 2334949 INFO  (qtp1341645024-37993) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[8 (1626992386571763712)]} 0 0
   [junit4]   2> 2334949 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386572812288,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334949 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386572812288
   [junit4]   2> 2334953 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2b84b89[collection2_shard1_replica_n1] main]
   [junit4]   2> 2334953 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2334955 INFO  (searcherExecutor-9198-thread-1-processing-n:127.0.0.1:44663_solr x:collection2_shard1_replica_n1 c:collection2 s:shard1 r:core_node3) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.c.SolrCore [collection2_shard1_replica_n1] Registered new searcher Searcher@2b84b89[collection2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851978}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620851991}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852000}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852010}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852020}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852033}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852047}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_7(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852056}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_8(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=9.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-137-generic, timestamp=1551620852065}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 2334955 INFO  (qtp1341645024-37989) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 5
   [junit4]   2> 2334959 INFO  (qtp1341645024-37990) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [collection2_shard1_replica_n1]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[9 (1626992386582249472)]} 0 1
   [junit4]   2> 2334960 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1626992386584346624,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2334960 INFO  (qtp1341645024-37991) [n:127.0.0.1:44663_solr c:collection2 s:shard1 r:core_node3 x:collection2_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2ada7602 commitCommandVersion:1626992386584346624
   [junit4]   2> 2334968 INFO

[...truncated too long message...]

set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null825231881
     [copy] Copying 239 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null825231881
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null825231881

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 54ms :: artifacts dl 4ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 288 minutes 23 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847)
	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726)
	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1072)
		at hudson.FilePath.act(FilePath.java:1061)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1835)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1074)
	at hudson.FilePath.act(FilePath.java:1061)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1835)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)

[JENKINS] Lucene-Solr-NightlyTests-master - Build # 1783 - Still Unstable

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1783/

3 tests failed.
FAILED:  org.apache.solr.TestDistributedGrouping.test

Error Message:
Error from server at https://127.0.0.1:42473/_imo/collection1: Error from server at null: java.lang.NullPointerException  at org.apache.solr.handler.component.ResponseBuilder.setResult(ResponseBuilder.java:466)  at org.apache.solr.handler.component.QueryComponent.doProcessGroupedDistributedSearchSecondPhase(QueryComponent.java:1369)  at org.apache.solr.handler.component.QueryComponent.process(QueryComponent.java:362)  at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:298)  at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)  at org.apache.solr.core.SolrCore.execute(SolrCore.java:2565)  at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:711)  at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:516)  at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:394)  at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:340)  at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)  at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:165)  at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)  at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)  at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)  at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)  at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)  at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)  at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)  at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)  at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)  at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)  at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:703)  at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)  at org.eclipse.jetty.server.Server.handle(Server.java:502)  at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)  at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)  at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)  at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)  at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:411)  at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:305)  at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:159)  at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)  at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)  at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)  at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)  at java.lang.Thread.run(Thread.java:748) 

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:42473/_imo/collection1: Error from server at null: java.lang.NullPointerException
	at org.apache.solr.handler.component.ResponseBuilder.setResult(ResponseBuilder.java:466)
	at org.apache.solr.handler.component.QueryComponent.doProcessGroupedDistributedSearchSecondPhase(QueryComponent.java:1369)
	at org.apache.solr.handler.component.QueryComponent.process(QueryComponent.java:362)
	at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:298)
	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
	at org.apache.solr.core.SolrCore.execute(SolrCore.java:2565)
	at org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:711)
	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:516)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:394)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:340)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:165)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:703)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
	at org.eclipse.jetty.server.Server.handle(Server.java:502)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
	at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:411)
	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:305)
	at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:159)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
	at java.lang.Thread.run(Thread.java:748)

	at __randomizedtesting.SeedInfo.seed([15E52028553B7669:9DB11FF2FBC71B91]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:649)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:987)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1002)
	at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:626)
	at org.apache.solr.TestDistributedGrouping.simpleQuery(TestDistributedGrouping.java:321)
	at org.apache.solr.TestDistributedGrouping.test(TestDistributedGrouping.java:309)
	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:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1108)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1054)
	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:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.autoscaling.HdfsAutoAddReplicasIntegrationTest.testSimple

Error Message:
Waiting for collection testSimple2 Timeout waiting to see state for collection=testSimple2 :DocCollection(testSimple2//collections/testSimple2/state.json/22)={   "pullReplicas":"0",   "replicationFactor":"2",   "shards":{     "shard1":{       "range":"80000000-ffffffff",       "state":"active",       "replicas":{         "core_node3":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/",           "base_url":"https://127.0.0.1:36352/solr",           "node_name":"127.0.0.1:36352_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/tlog",           "core":"testSimple2_shard1_replica_n1",           "shared_storage":"true",           "state":"down"},         "core_node5":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/",           "base_url":"https://127.0.0.1:46093/solr",           "node_name":"127.0.0.1:46093_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/tlog",           "core":"testSimple2_shard1_replica_n2",           "shared_storage":"true",           "state":"active",           "leader":"true"}}},     "shard2":{       "range":"0-7fffffff",       "state":"active",       "replicas":{         "core_node7":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/",           "base_url":"https://127.0.0.1:36352/solr",           "node_name":"127.0.0.1:36352_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/tlog",           "core":"testSimple2_shard2_replica_n4",           "shared_storage":"true",           "state":"down"},         "core_node8":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/",           "base_url":"https://127.0.0.1:46093/solr",           "node_name":"127.0.0.1:46093_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/tlog",           "core":"testSimple2_shard2_replica_n6",           "shared_storage":"true",           "state":"active",           "leader":"true"}}}},   "router":{"name":"compositeId"},   "maxShardsPerNode":"2",   "autoAddReplicas":"true",   "nrtReplicas":"2",   "tlogReplicas":"0"} Live Nodes: [127.0.0.1:34550_solr, 127.0.0.1:46093_solr] Last available state: DocCollection(testSimple2//collections/testSimple2/state.json/22)={   "pullReplicas":"0",   "replicationFactor":"2",   "shards":{     "shard1":{       "range":"80000000-ffffffff",       "state":"active",       "replicas":{         "core_node3":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/",           "base_url":"https://127.0.0.1:36352/solr",           "node_name":"127.0.0.1:36352_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/tlog",           "core":"testSimple2_shard1_replica_n1",           "shared_storage":"true",           "state":"down"},         "core_node5":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/",           "base_url":"https://127.0.0.1:46093/solr",           "node_name":"127.0.0.1:46093_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/tlog",           "core":"testSimple2_shard1_replica_n2",           "shared_storage":"true",           "state":"active",           "leader":"true"}}},     "shard2":{       "range":"0-7fffffff",       "state":"active",       "replicas":{         "core_node7":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/",           "base_url":"https://127.0.0.1:36352/solr",           "node_name":"127.0.0.1:36352_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/tlog",           "core":"testSimple2_shard2_replica_n4",           "shared_storage":"true",           "state":"down"},         "core_node8":{           "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/",           "base_url":"https://127.0.0.1:46093/solr",           "node_name":"127.0.0.1:46093_solr",           "type":"NRT",           "force_set_state":"false",           "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/tlog",           "core":"testSimple2_shard2_replica_n6",           "shared_storage":"true",           "state":"active",           "leader":"true"}}}},   "router":{"name":"compositeId"},   "maxShardsPerNode":"2",   "autoAddReplicas":"true",   "nrtReplicas":"2",   "tlogReplicas":"0"}

Stack Trace:
java.lang.AssertionError: Waiting for collection testSimple2
Timeout waiting to see state for collection=testSimple2 :DocCollection(testSimple2//collections/testSimple2/state.json/22)={
  "pullReplicas":"0",
  "replicationFactor":"2",
  "shards":{
    "shard1":{
      "range":"80000000-ffffffff",
      "state":"active",
      "replicas":{
        "core_node3":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/",
          "base_url":"https://127.0.0.1:36352/solr",
          "node_name":"127.0.0.1:36352_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/tlog",
          "core":"testSimple2_shard1_replica_n1",
          "shared_storage":"true",
          "state":"down"},
        "core_node5":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/",
          "base_url":"https://127.0.0.1:46093/solr",
          "node_name":"127.0.0.1:46093_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/tlog",
          "core":"testSimple2_shard1_replica_n2",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}},
    "shard2":{
      "range":"0-7fffffff",
      "state":"active",
      "replicas":{
        "core_node7":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/",
          "base_url":"https://127.0.0.1:36352/solr",
          "node_name":"127.0.0.1:36352_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/tlog",
          "core":"testSimple2_shard2_replica_n4",
          "shared_storage":"true",
          "state":"down"},
        "core_node8":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/",
          "base_url":"https://127.0.0.1:46093/solr",
          "node_name":"127.0.0.1:46093_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/tlog",
          "core":"testSimple2_shard2_replica_n6",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}}},
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"2",
  "autoAddReplicas":"true",
  "nrtReplicas":"2",
  "tlogReplicas":"0"}
Live Nodes: [127.0.0.1:34550_solr, 127.0.0.1:46093_solr]
Last available state: DocCollection(testSimple2//collections/testSimple2/state.json/22)={
  "pullReplicas":"0",
  "replicationFactor":"2",
  "shards":{
    "shard1":{
      "range":"80000000-ffffffff",
      "state":"active",
      "replicas":{
        "core_node3":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/",
          "base_url":"https://127.0.0.1:36352/solr",
          "node_name":"127.0.0.1:36352_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node3/data/tlog",
          "core":"testSimple2_shard1_replica_n1",
          "shared_storage":"true",
          "state":"down"},
        "core_node5":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/",
          "base_url":"https://127.0.0.1:46093/solr",
          "node_name":"127.0.0.1:46093_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node5/data/tlog",
          "core":"testSimple2_shard1_replica_n2",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}},
    "shard2":{
      "range":"0-7fffffff",
      "state":"active",
      "replicas":{
        "core_node7":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/",
          "base_url":"https://127.0.0.1:36352/solr",
          "node_name":"127.0.0.1:36352_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node7/data/tlog",
          "core":"testSimple2_shard2_replica_n4",
          "shared_storage":"true",
          "state":"down"},
        "core_node8":{
          "dataDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/",
          "base_url":"https://127.0.0.1:46093/solr",
          "node_name":"127.0.0.1:46093_solr",
          "type":"NRT",
          "force_set_state":"false",
          "ulogDir":"hdfs://localhost:41085/solr_hdfs_home/testSimple2/core_node8/data/tlog",
          "core":"testSimple2_shard2_replica_n6",
          "shared_storage":"true",
          "state":"active",
          "leader":"true"}}}},
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"2",
  "autoAddReplicas":"true",
  "nrtReplicas":"2",
  "tlogReplicas":"0"}
	at __randomizedtesting.SeedInfo.seed([15E52028553B7669:2D5604D672C8A2B8]:0)
	at org.junit.Assert.fail(Assert.java:88)
	at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:310)
	at org.apache.solr.cloud.autoscaling.AutoAddReplicasIntegrationTest.testSimple(AutoAddReplicasIntegrationTest.java:169)
	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:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	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:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.handler.export.TestExportWriter.testIndexOrder

Error Message:
expected:<...ocs":[       {"id":"[1"},       {"id":"2"},       {"id":"3"},       {"id":"4]"}]}}> but was:<...ocs":[       {"id":"[3"},       {"id":"4"},       {"id":"1"},       {"id":"2]"}]}}>

Stack Trace:
org.junit.ComparisonFailure: expected:<...ocs":[
      {"id":"[1"},
      {"id":"2"},
      {"id":"3"},
      {"id":"4]"}]}}> but was:<...ocs":[
      {"id":"[3"},
      {"id":"4"},
      {"id":"1"},
      {"id":"2]"}]}}>
	at __randomizedtesting.SeedInfo.seed([15E52028553B7669:DCA38EAC7E924297]:0)
	at org.junit.Assert.assertEquals(Assert.java:115)
	at org.junit.Assert.assertEquals(Assert.java:144)
	at org.apache.solr.handler.export.TestExportWriter.assertJsonEquals(TestExportWriter.java:523)
	at org.apache.solr.handler.export.TestExportWriter.testIndexOrder(TestExportWriter.java:335)
	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:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	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:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	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 13465 lines...]
   [junit4] Suite: org.apache.solr.TestDistributedGrouping
   [junit4]   2> 543596 INFO  (SUITE-TestDistributedGrouping-seed#[15E52028553B7669]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/init-core-data-001
   [junit4]   2> 543599 WARN  (SUITE-TestDistributedGrouping-seed#[15E52028553B7669]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 543599 INFO  (SUITE-TestDistributedGrouping-seed#[15E52028553B7669]-worker) [    ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 543603 INFO  (SUITE-TestDistributedGrouping-seed#[15E52028553B7669]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
   [junit4]   2> 543603 INFO  (SUITE-TestDistributedGrouping-seed#[15E52028553B7669]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_imo/
   [junit4]   2> 543880 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/control/cores/collection1
   [junit4]   2> 543883 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 543883 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 543883 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 543883 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 543885 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 543885 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 543885 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 543887 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4364796a{/_imo,null,AVAILABLE}
   [junit4]   2> 543888 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@5c24bb19[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 543888 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@7709c4d8{SSL,[ssl, http/1.1]}{127.0.0.1:34711}
   [junit4]   2> 543888 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.Server Started @543949ms
   [junit4]   2> 543888 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/_imo, hostPort=34711, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/control/cores}
   [junit4]   2> 543889 ERROR (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 9.0.0
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-03-04T20:50:09.245Z
   [junit4]   2> 543889 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/control/solr.xml
   [junit4]   2> 543894 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 543894 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 543896 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 543994 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
   [junit4]   2> 543995 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 543998 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@587763d[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 544008 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 544009 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7592957e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 544051 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
   [junit4]   2> 544051 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 544085 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 544100 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 544100 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 544103 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/control/cores
   [junit4]   2> 544103 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 544106 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 544168 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 544197 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 544343 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 544372 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 544372 INFO  (coreLoadExecutor-2013-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@2a7e34b8
   [junit4]   2> 544373 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/control/cores/collection1/data/]
   [junit4]   2> 544376 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1078672278, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 544462 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 544462 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 544465 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 544465 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 544466 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31870354055113853]
   [junit4]   2> 544467 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7098c077[collection1] main]
   [junit4]   2> 544468 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 544480 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 544531 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 544531 INFO  (coreLoadExecutor-2013-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1627109573144870912
   [junit4]   2> 544534 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 544534 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 544534 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 544534 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 544535 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 544535 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 544535 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 544536 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 544536 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 544542 INFO  (searcherExecutor-2014-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7098c077[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 544708 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/shard0/cores/collection1
   [junit4]   2> 544719 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 544719 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 544720 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 544720 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 544721 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 544721 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 544721 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 544721 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7404aee5{/_imo,null,AVAILABLE}
   [junit4]   2> 544722 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@372bcf67[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.AbstractConnector Started ServerConnector@4ba93315{SSL,[ssl, http/1.1]}{127.0.0.1:42473}
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.s.Server Started @544784ms
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/_imo, hostPort=42473, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/shard0/cores}
   [junit4]   2> 544723 ERROR (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 9.0.0
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 544723 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-03-04T20:50:10.079Z
   [junit4]   2> 544724 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/shard0/solr.xml
   [junit4]   2> 544729 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 544729 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 544731 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 544834 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
   [junit4]   2> 544835 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 544858 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@245deaf5[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 544863 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 544864 WARN  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6ab82ec1[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 544907 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
   [junit4]   2> 544907 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 544985 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 545016 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 545017 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a7e34b8
   [junit4]   2> 545023 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/shard0/cores
   [junit4]   2> 545023 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 545024 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 545075 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 545106 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 545258 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 545269 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 545270 INFO  (coreLoadExecutor-2027-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@2a7e34b8
   [junit4]   2> 545270 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.TestDistributedGrouping_15E52028553B7669-001/tempDir-001/shard0/cores/collection1/data/]
   [junit4]   2> 545273 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1078672278, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 545351 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 545351 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 545354 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 545354 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 545356 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.31870354055113853]
   [junit4]   2> 545356 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1222fc0d[collection1] main]
   [junit4]   2> 545357 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 545369 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 545438 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 545442 INFO  (coreLoadExecutor-2027-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1627109574100123648
   [junit4]   2> 545444 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 545445 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 545445 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 545445 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 545445 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 545447 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 545448 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 545449 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 545451 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 545453 INFO  (searcherExecutor-2028-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1222fc0d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 545947 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 545994 INFO  (qtp350246734-6769) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/_imo path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1627109574672646144)} 0 6
   [junit4]   2> 546018 INFO  (qtp884358071-6793) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/_imo path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1627109574699909120)} 0 4
   [junit4]   2> 546025 INFO  (qtp350246734-6770) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1627109574711443456,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 546025 INFO  (qtp350246734-6770) [    x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 546026 INFO  (qtp350246734-6770) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 546026 INFO  (qtp350246734-6770) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/_imo path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1
   [junit4]   2> 546033 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1627109574719832064,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 546033 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 546034 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 546034 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/_imo path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 1
   [junit4]   2> 546057 INFO  (qtp350246734-6771) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&distrib=false&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} hits=0 status=0 QTime=21
   [junit4]   2> 546302 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611417&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=24
   [junit4]   2> 546329 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=268
   [junit4]   2> 546329 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.BaseDistributedSearchTestCase starting stress...
   [junit4]   2> 546346 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611698&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546351 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=8
   [junit4]   2> 546355 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611702&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546363 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=17
   [junit4]   2> 546380 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611734&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546387 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611708&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=2
   [junit4]   2> 546421 INFO  (qtp884358071-6793) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=69
   [junit4]   2> 546421 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=43
   [junit4]   2> 546424 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611704&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546431 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=83
   [junit4]   2> 546435 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611789&isShard=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546436 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1|[ff01::213]:33332/_imo&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=3
   [junit4]   2> 546442 INFO  (qtp350246734-6767) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&distrib=false&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} hits=0 status=0 QTime=4
   [junit4]   2> 546446 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611800&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546448 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=3
   [junit4]   2> 546448 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.BaseDistributedSearchTestCase starting stress...
   [junit4]   2> 546454 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611807&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546455 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611809&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546455 INFO  (qtp884358071-6793) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=4
   [junit4]   2> 546456 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=2
   [junit4]   2> 546457 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611812&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546458 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=2
   [junit4]   2> 546464 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611809&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546465 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=12
   [junit4]   2> 546467 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611821&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546468 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=2
   [junit4]   2> 546469 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&hl=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611824&isShard=true&hl.fl=a_t&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546470 INFO  (qtp884358071-6793) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::114]:33332/_imo&hl=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&hl.fl=a_t&rows=100&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=2
   [junit4]   2> 546486 INFO  (qtp350246734-6768) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&facet.field=a_t&distrib=false&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} hits=0 status=0 QTime=14
   [junit4]   2> 546490 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611845&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546509 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611845&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=7
   [junit4]   2> 546517 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=28
   [junit4]   2> 546518 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.BaseDistributedSearchTestCase starting stress...
   [junit4]   2> 546522 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611876&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546522 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611876&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546523 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611878&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546524 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611876&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546524 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611876&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546525 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=5
   [junit4]   2> 546525 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=5
   [junit4]   2> 546527 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611878&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546528 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=5
   [junit4]   2> 546529 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611884&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546531 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611885&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546534 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611884&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546534 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611885&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546535 INFO  (qtp884358071-6793) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=6
   [junit4]   2> 546535 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=6
   [junit4]   2> 546538 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&q=*:*&NOW=1551732611892&isShard=true&facet=false&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546540 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={facet.field=a_t&df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=20&start=0&f.a_t.facet.mincount=0&sort=a_i1+asc,+id+asc&shard.url=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&rows=100&version=2&group.distributed.second=true&q=*:*&f.a_t.facet.limit=160&NOW=1551732611892&isShard=true&facet=true&wt=javabin&group.field=a_i1&group=true} status=0 QTime=0
   [junit4]   2> 546541 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=https://127.0.0.1:42473/_imo/collection1|[ff01::083]:33332/_imo&facet.field=a_t&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&facet=true&wt=javabin&version=2&group.field=a_i1&group=true} status=0 QTime=4
   [junit4]   2> 546562 INFO  (qtp350246734-6769) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&distrib=false&stats=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true&stats.field=a_i1} hits=0 status=0 QTime=19
   [junit4]   2> 546568 INFO  (qtp884358071-6792) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&q=*:*&stats=false&NOW=1551732611921&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546571 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=516&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&group.distributed.second=true&q=*:*&stats=true&NOW=1551732611921&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=1
   [junit4]   2> 546573 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&stats=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=7
   [junit4]   2> 546574 INFO  (TEST-TestDistributedGrouping.test-seed#[15E52028553B7669]) [    ] o.a.s.BaseDistributedSearchTestCase starting stress...
   [junit4]   2> 546577 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&q=*:*&stats=false&NOW=1551732611931&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546578 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&q=*:*&stats=false&NOW=1551732611932&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546578 INFO  (qtp884358071-6839) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&group.distributed.first=true&distrib=false&fl=id&group.limit=-1&shards.purpose=2048&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&q=*:*&stats=false&NOW=1551732611931&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546581 INFO  (qtp884358071-6791) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=516&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&group.distributed.second=true&q=*:*&stats=true&NOW=1551732611931&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546582 INFO  (qtp884358071-6794) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=516&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&group.distributed.second=true&q=*:*&stats=true&NOW=1551732611932&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546583 INFO  (qtp884358071-6838) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={df=text&distrib=false&fl=id&group.limit=-1&shards.purpose=516&start=0&sort=a_i1+asc,+id+asc&shard.url=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&rows=100&version=2&group.distributed.second=true&q=*:*&stats=true&NOW=1551732611931&isShard=true&wt=javabin&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=0
   [junit4]   2> 546583 INFO  (qtp884358071-6790) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&stats=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=6
   [junit4]   2> 546583 INFO  (qtp884358071-6837) [    x:collection1] o.a.s.c.S.Request [collection1]  webapp=/_imo path=/select params={q=*:*&shards=[ff01::083]:33332/_imo|[ff01::114]:33332/_imo|https://127.0.0.1:42473/_imo/collection1&stats=true&fl=id,a_i1&group.limit=-1&sort=a_i1+asc,+id+asc&rows=100&wt=javabin&version=2&group.field=a_i1&group=true&stats.field=a_i1} status=0 QTime=8
   [junit4]   2> 546584 INFO  (qtp884358071-6793) [    x:collecti

[...truncated too long message...]

 property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1904382940
     [copy] Copying 239 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1904382940
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1904382940

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 51ms :: artifacts dl 4ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 378 minutes 57 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847)
	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726)
	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1072)
		at hudson.FilePath.act(FilePath.java:1061)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1835)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1074)
	at hudson.FilePath.act(FilePath.java:1061)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1835)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)