You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/10/31 10:54:06 UTC
[JENKINS] Lucene-Solr-7.x-MacOSX (64bit/jdk1.8.0) - Build # 273 -
Failure!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/273/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI
Error Message:
Could not find collection : implicitcoll
Stack Trace:
org.apache.solr.common.SolrException: Could not find collection : implicitcoll
at __randomizedtesting.SeedInfo.seed([24D85E0053680E6F:4E39D06B6EF2B817]:0)
at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:111)
at org.apache.solr.cloud.SolrCloudTestCase.getCollectionState(SolrCloudTestCase.java:247)
at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:68)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11561 lines...]
[junit4] JVM J0: stdout was not empty, see: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20171031_092905_1572242955450279347941.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] #
[junit4] # A fatal error has been detected by the Java Runtime Environment:
[junit4] #
[junit4] # Internal Error (sharedRuntime.cpp:873), pid=14660, tid=0x0000000000009527
[junit4] # guarantee(nm != NULL) failed: must have containing nmethod for implicit division-by-zero exceptions
[junit4] #
[junit4] # JRE version: Java(TM) SE Runtime Environment (8.0_144-b01) (build 1.8.0_144-b01)
[junit4] # Java VM: Java HotSpot(TM) 64-Bit Server VM (25.144-b01 mixed mode bsd-amd64 compressed oops)
[junit4] # Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
[junit4] #
[junit4] # An error report file with more information is saved as:
[junit4] # /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/hs_err_pid14660.log
[junit4] #
[junit4] # If you would like to submit a bug report, please visit:
[junit4] # http://bugreport.java.com/bugreport/crash.jsp
[junit4] #
[junit4] <<< JVM J0: EOF ----
[...truncated 1018 lines...]
[junit4] Suite: org.apache.solr.cloud.CustomCollectionTest
[junit4] 2> 2721895 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/init-core-data-001
[junit4] 2> 2721896 WARN (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 2721897 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2721902 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 2721907 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001
[junit4] 2> 2721907 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2721908 INFO (Thread-4001) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2721908 INFO (Thread-4001) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2721917 ERROR (Thread-4001) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 2722018 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:56552
[junit4] 2> 2722056 INFO (jetty-launcher-3399-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2722057 INFO (jetty-launcher-3399-thread-4) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2722057 INFO (jetty-launcher-3399-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2722056 INFO (jetty-launcher-3399-thread-3) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2722069 INFO (jetty-launcher-3399-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@731ea186{/solr,null,AVAILABLE}
[junit4] 2> 2722070 INFO (jetty-launcher-3399-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@112c5162{SSL,[ssl, http/1.1]}{127.0.0.1:56554}
[junit4] 2> 2722070 INFO (jetty-launcher-3399-thread-3) [ ] o.e.j.s.Server Started @2725287ms
[junit4] 2> 2722070 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56554}
[junit4] 2> 2722071 ERROR (jetty-launcher-3399-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2722071 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 2722071 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2722071 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2722071 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T10:14:30.495Z
[junit4] 2> 2722074 INFO (jetty-launcher-3399-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@638c44a2{/solr,null,AVAILABLE}
[junit4] 2> 2722075 INFO (jetty-launcher-3399-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2a1f82e{SSL,[ssl, http/1.1]}{127.0.0.1:56555}
[junit4] 2> 2722075 INFO (jetty-launcher-3399-thread-2) [ ] o.e.j.s.Server Started @2725291ms
[junit4] 2> 2722075 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56555}
[junit4] 2> 2722075 ERROR (jetty-launcher-3399-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2722076 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 2722076 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2722076 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2722076 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T10:14:30.500Z
[junit4] 2> 2722079 INFO (jetty-launcher-3399-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@484997d1{/solr,null,AVAILABLE}
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@786a5113{SSL,[ssl, http/1.1]}{127.0.0.1:56558}
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.e.j.s.Server Started @2725296ms
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56558}
[junit4] 2> 2722080 ERROR (jetty-launcher-3399-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2722080 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T10:14:30.504Z
[junit4] 2> 2722082 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2722083 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2722104 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2722122 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15f71ece0c00001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2722130 INFO (jetty-launcher-3399-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56552/solr
[junit4] 2> 2722131 INFO (jetty-launcher-3399-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@69ea1942{/solr,null,AVAILABLE}
[junit4] 2> 2722134 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15f71ece0c00004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2722144 INFO (jetty-launcher-3399-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56552/solr
[junit4] 2> 2722168 INFO (jetty-launcher-3399-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@63c7bd8b{SSL,[ssl, http/1.1]}{127.0.0.1:56561}
[junit4] 2> 2722168 INFO (jetty-launcher-3399-thread-4) [ ] o.e.j.s.Server Started @2725385ms
[junit4] 2> 2722169 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=56561}
[junit4] 2> 2722169 INFO (jetty-launcher-3399-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56552/solr
[junit4] 2> 2722169 ERROR (jetty-launcher-3399-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2722170 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 2722170 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2722170 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2722170 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T10:14:30.594Z
[junit4] 2> 2722189 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2722233 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15f71ece0c00009, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2722236 INFO (jetty-launcher-3399-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:56552/solr
[junit4] 2> 2722302 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2722304 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56558_solr
[junit4] 2> 2722307 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.c.Overseer Overseer (id=98922979022340106-127.0.0.1:56558_solr-n_0000000000) starting
[junit4] 2> 2722314 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2722319 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56561_solr
[junit4] 2> 2722324 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2722324 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2722342 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56558_solr
[junit4] 2> 2722353 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2722354 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2722497 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2722505 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2722508 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2722511 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56554_solr
[junit4] 2> 2722514 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2722514 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2722514 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2722516 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2722516 INFO (zkCallback-3412-thread-1-processing-n:127.0.0.1:56555_solr) [n:127.0.0.1:56555_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2722523 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56555_solr
[junit4] 2> 2722525 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2722525 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2722525 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2722544 INFO (zkCallback-3412-thread-1-processing-n:127.0.0.1:56555_solr) [n:127.0.0.1:56555_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2722730 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56561.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722735 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56558.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722764 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56554.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722766 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56561.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722767 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56561.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722768 INFO (jetty-launcher-3399-thread-4) [n:127.0.0.1:56561_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node4/.
[junit4] 2> 2722776 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56555.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722794 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56554.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722794 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56554.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722804 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56555.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722804 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56555.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722804 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56558.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722805 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56558.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2722805 INFO (jetty-launcher-3399-thread-2) [n:127.0.0.1:56555_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node2/.
[junit4] 2> 2722804 INFO (jetty-launcher-3399-thread-3) [n:127.0.0.1:56554_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node3/.
[junit4] 2> 2722807 INFO (jetty-launcher-3399-thread-1) [n:127.0.0.1:56558_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node1/.
[junit4] 2> 2722957 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15f71ece0c0000d, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2722964 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2722965 INFO (SUITE-CustomCollectionTest-seed#[24D85E0053680E6F]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:56552/solr ready
[junit4] 2> 2723373 INFO (TEST-CustomCollectionTest.testCreateShardRepFactor-seed#[24D85E0053680E6F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateShardRepFactor
[junit4] 2> 2723376 INFO (TEST-CustomCollectionTest.testCreateShardRepFactor-seed#[24D85E0053680E6F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2723419 INFO (qtp843186363-21052) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params shards=a,b&replicationFactor=1&collection.configName=conf&name=testCreateShardRepFactor&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2723423 INFO (OverseerThreadFactory-9455-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateCollectionCmd Create collection testCreateShardRepFactor
[junit4] 2> 2723572 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testCreateShardRepFactor",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"testCreateShardRepFactor_a_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2723585 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testCreateShardRepFactor",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"testCreateShardRepFactor_b_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2723838 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_b_replica_n2&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=b&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2723839 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2723863 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_a_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=a&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2723864 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2723980 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2723980 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2723981 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2723981 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2724882 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2724888 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2724889 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.s.IndexSchema [testCreateShardRepFactor_b_replica_n2] Schema name=cloud-dynamic
[junit4] 2> 2724893 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.IndexSchema [testCreateShardRepFactor_a_replica_n1] Schema name=cloud-dynamic
[junit4] 2> 2724929 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id
[junit4] 2> 2724929 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_b_replica_n2' using configuration from collection testCreateShardRepFactor, trusted=true
[junit4] 2> 2724930 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56554.solr.core.testCreateShardRepFactor.b.replica_n2' (registry 'solr.core.testCreateShardRepFactor.b.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2724930 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2724930 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SolrCore [[testCreateShardRepFactor_b_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node3/testCreateShardRepFactor_b_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node3/./testCreateShardRepFactor_b_replica_n2/data/]
[junit4] 2> 2724930 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id
[junit4] 2> 2724930 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_a_replica_n1' using configuration from collection testCreateShardRepFactor, trusted=true
[junit4] 2> 2724930 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56561.solr.core.testCreateShardRepFactor.a.replica_n1' (registry 'solr.core.testCreateShardRepFactor.a.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2724931 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2724931 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore [[testCreateShardRepFactor_a_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node4/testCreateShardRepFactor_a_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node4/./testCreateShardRepFactor_a_replica_n1/data/]
[junit4] 2> 2724988 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2724988 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2724990 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2724990 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2724991 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f4a0347[testCreateShardRepFactor_a_replica_n1] main]
[junit4] 2> 2724992 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2724992 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2724993 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2724993 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582767667588104192
[junit4] 2> 2724994 INFO (searcherExecutor-9465-thread-1-processing-n:127.0.0.1:56561_solr x:testCreateShardRepFactor_a_replica_n1 s:a c:testCreateShardRepFactor r:core_node3) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore [testCreateShardRepFactor_a_replica_n1] Registered new searcher Searcher@3f4a0347[testCreateShardRepFactor_a_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2724997 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2724997 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2724998 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2724999 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2725000 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@41c75524[testCreateShardRepFactor_b_replica_n2] main]
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:56561/solr/testCreateShardRepFactor_a_replica_n1/
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:56561/solr/testCreateShardRepFactor_a_replica_n1/ has no replicas
[junit4] 2> 2725000 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2725002 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2725002 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2725003 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2725004 INFO (searcherExecutor-9464-thread-1-processing-n:127.0.0.1:56554_solr x:testCreateShardRepFactor_b_replica_n2 s:b c:testCreateShardRepFactor r:core_node4) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SolrCore [testCreateShardRepFactor_b_replica_n2] Registered new searcher Searcher@41c75524[testCreateShardRepFactor_b_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2725004 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582767667599638528
[junit4] 2> 2725006 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:56561/solr/testCreateShardRepFactor_a_replica_n1/ a
[junit4] 2> 2725011 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2725012 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2725012 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:56554/solr/testCreateShardRepFactor_b_replica_n2/
[junit4] 2> 2725012 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2725012 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:56554/solr/testCreateShardRepFactor_b_replica_n2/ has no replicas
[junit4] 2> 2725012 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2725017 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:56554/solr/testCreateShardRepFactor_b_replica_n2/ b
[junit4] 2> 2725120 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725120 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725120 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725120 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725134 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2725136 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr c:testCreateShardRepFactor s:b r:core_node4 x:testCreateShardRepFactor_b_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_b_replica_n2&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=b&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1297
[junit4] 2> 2725179 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2725181 INFO (qtp169223275-21043) [n:127.0.0.1:56561_solr c:testCreateShardRepFactor s:a r:core_node3 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_a_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=a&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1317
[junit4] 2> 2725187 INFO (qtp843186363-21052) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2725288 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725288 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725288 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725288 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2725438 INFO (OverseerCollectionConfigSetProcessor-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2726193 INFO (qtp843186363-21052) [n:127.0.0.1:56554_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={shards=a,b&replicationFactor=1&collection.configName=conf&name=testCreateShardRepFactor&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2} status=0 QTime=2774
[junit4] 2> 2726194 INFO (qtp843186363-21048) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createshard with params action=CREATESHARD&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2726197 INFO (OverseerThreadFactory-9455-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateShardCmd Create shard invoked: {
[junit4] 2> "collection":"testCreateShardRepFactor",
[junit4] 2> "shard":"x",
[junit4] 2> "operation":"createshard"}
[junit4] 2> 2726303 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2726303 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2726303 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2726303 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727208 INFO (OverseerThreadFactory-9455-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateShardCmd Creating replica testCreateShardRepFactor_x_replica_n5 as part of slice x of collection testCreateShardRepFactor on 127.0.0.1:56558_solr
[junit4] 2> 2727210 INFO (OverseerThreadFactory-9455-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:56558_solr for creating new replica
[junit4] 2> 2727212 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"testCreateShardRepFactor",
[junit4] 2> "shard":"x",
[junit4] 2> "core":"testCreateShardRepFactor_x_replica_n5",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "node_name":"127.0.0.1:56558_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 2727323 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727323 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727323 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727323 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727457 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&name=testCreateShardRepFactor_x_replica_n5&action=CREATE&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2727458 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2727473 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2727479 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.s.IndexSchema [testCreateShardRepFactor_x_replica_n5] Schema name=cloud-dynamic
[junit4] 2> 2727495 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id
[junit4] 2> 2727495 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_x_replica_n5' using configuration from collection testCreateShardRepFactor, trusted=true
[junit4] 2> 2727496 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56558.solr.core.testCreateShardRepFactor.x.replica_n5' (registry 'solr.core.testCreateShardRepFactor.x.replica_n5') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@583e2794
[junit4] 2> 2727496 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2727496 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SolrCore [[testCreateShardRepFactor_x_replica_n5] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node1/testCreateShardRepFactor_x_replica_n5], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_24D85E0053680E6F-001/tempDir-001/node1/./testCreateShardRepFactor_x_replica_n5/data/]
[junit4] 2> 2727569 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2727570 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2727570 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727570 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727570 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727570 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727570 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727571 INFO (zkCallback-3419-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727572 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2727572 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2727573 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.s.SolrIndexSearcher Opening [Searcher@1cb374ef[testCreateShardRepFactor_x_replica_n5] main]
[junit4] 2> 2727575 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2727575 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2727575 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2727576 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582767670296576000
[junit4] 2> 2727576 INFO (searcherExecutor-9474-thread-1-processing-n:127.0.0.1:56558_solr x:testCreateShardRepFactor_x_replica_n5 s:x c:testCreateShardRepFactor r:core_node6) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SolrCore [testCreateShardRepFactor_x_replica_n5] Registered new searcher Searcher@1cb374ef[testCreateShardRepFactor_x_replica_n5] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2727581 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2727581 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2727581 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:56558/solr/testCreateShardRepFactor_x_replica_n5/
[junit4] 2> 2727581 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2727581 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.SyncStrategy https://127.0.0.1:56558/solr/testCreateShardRepFactor_x_replica_n5/ has no replicas
[junit4] 2> 2727582 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2727587 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:56558/solr/testCreateShardRepFactor_x_replica_n5/ x
[junit4] 2> 2727699 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727699 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727699 INFO (zkCallback-3419-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727699 INFO (zkCallback-3419-thread-3-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727699 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727699 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727758 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2727760 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr c:testCreateShardRepFactor s:x r:core_node6 x:testCreateShardRepFactor_x_replica_n5] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&name=testCreateShardRepFactor_x_replica_n5&action=CREATE&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2&replicaType=NRT} status=0 QTime=302
[junit4] 2> 2727760 INFO (OverseerThreadFactory-9455-thread-2-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateShardCmd Finished create command on all shards for collection: testCreateShardRepFactor
[junit4] 2> 2727762 INFO (qtp843186363-21048) [n:127.0.0.1:56554_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CREATESHARD&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2} status=0 QTime=1568
[junit4] 2> 2727764 INFO (TEST-CustomCollectionTest.testCreateShardRepFactor-seed#[24D85E0053680E6F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateShardRepFactor
[junit4] 2> 2727900 INFO (zkCallback-3419-thread-1-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727900 INFO (zkCallback-3419-thread-3-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727902 INFO (zkCallback-3408-thread-1-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727902 INFO (zkCallback-3423-thread-2-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727902 INFO (zkCallback-3408-thread-2-processing-n:127.0.0.1:56554_solr) [n:127.0.0.1:56554_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727904 INFO (zkCallback-3423-thread-1-processing-n:127.0.0.1:56561_solr) [n:127.0.0.1:56561_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2727983 INFO (TEST-CustomCollectionTest.testRouteFieldForImplicitRouter-seed#[24D85E0053680E6F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRouteFieldForImplicitRouter
[junit4] 2> 2727984 INFO (TEST-CustomCollectionTest.testRouteFieldForImplicitRouter-seed#[24D85E0053680E6F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2727987 INFO (qtp843186363-21050) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=testCreateShardRepFactor&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2727991 INFO (OverseerThreadFactory-9455-thread-3-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 2727992 INFO (OverseerCollectionConfigSetProcessor-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2727998 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.b.replica_n2, tag=null
[junit4] 2> 2727998 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.a.replica_n1, tag=null
[junit4] 2> 2727998 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@20db8f1d: rootName = solr_56554, domain = solr.core.testCreateShardRepFactor.b.replica_n2, service url = null, agent id = null] for registry solr.core.testCreateShardRepFactor.b.replica_n2 / com.codahale.metrics.MetricRegistry@4b4e573b
[junit4] 2> 2728000 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4d9a31d8: rootName = solr_56561, domain = solr.core.testCreateShardRepFactor.a.replica_n1, service url = null, agent id = null] for registry solr.core.testCreateShardRepFactor.a.replica_n1 / com.codahale.metrics.MetricRegistry@46a80d4b
[junit4] 2> 2728001 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.x.replica_n5, tag=null
[junit4] 2> 2728001 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@48dc8c92: rootName = solr_56558, domain = solr.core.testCreateShardRepFactor.x.replica_n5, service url = null, agent id = null] for registry solr.core.testCreateShardRepFactor.x.replica_n5 / com.codahale.metrics.MetricRegistry@2dfd39d8
[junit4] 2> 2728123 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.c.SolrCore [testCreateShardRepFactor_a_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@37f8c364
[junit4] 2> 2728123 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.a.replica_n1, tag=939049828
[junit4] 2> 2728123 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testCreateShardRepFactor.a.leader, tag=939049828
[junit4] 2> 2728123 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.c.SolrCore [testCreateShardRepFactor_b_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@494a76ef
[junit4] 2> 2728126 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.b.replica_n2, tag=1229616879
[junit4] 2> 2728126 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testCreateShardRepFactor.b.leader, tag=1229616879
[junit4] 2> 2728126 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.c.SolrCore [testCreateShardRepFactor_x_replica_n5] CLOSING SolrCore org.apache.solr.core.SolrCore@1db390b4
[junit4] 2> 2728126 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCreateShardRepFactor.x.replica_n5, tag=498307252
[junit4] 2> 2728128 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testCreateShardRepFactor.x.leader, tag=498307252
[junit4] 2> 2728136 INFO (qtp169223275-21044) [n:127.0.0.1:56561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=testCreateShardRepFactor_a_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=141
[junit4] 2> 2728136 INFO (qtp843186363-21051) [n:127.0.0.1:56554_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=testCreateShardRepFactor_b_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=143
[junit4] 2> 2728137 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=testCreateShardRepFactor_x_replica_n5&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=136
[junit4] 2> 2728862 INFO (qtp843186363-21050) [n:127.0.0.1:56554_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=testCreateShardRepFactor&action=DELETE&wt=javabin&version=2} status=0 QTime=875
[junit4] 2> 2728863 INFO (qtp843186363-21054) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params shards=a,b,c,d&replicationFactor=5&collection.configName=conf&maxShardsPerNode=6&router.field=shard_s&name=withShardField&router.name=implicit&nrtReplicas=5&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2728866 INFO (OverseerThreadFactory-9455-thread-4-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateCollectionCmd Create collection withShardField
[junit4] 2> 2728866 INFO (OverseerCollectionConfigSetProcessor-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2728867 WARN (OverseerThreadFactory-9455-thread-4-processing-n:127.0.0.1:56558_solr) [n:127.0.0.1:56558_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 5 on collection withShardField is higher than the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 2729098 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"withShardField_a_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56555/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729102 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"withShardField_a_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729105 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"withShardField_a_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729109 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"withShardField_a_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729111 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"a",
[junit4] 2> "core":"withShardField_a_replica_n8",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56555/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729119 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"withShardField_b_replica_n10",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729122 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"withShardField_b_replica_n12",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729126 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"withShardField_b_replica_n14",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729130 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"withShardField_b_replica_n16",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56555/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729133 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"b",
[junit4] 2> "core":"withShardField_b_replica_n18",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729137 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"c",
[junit4] 2> "core":"withShardField_c_replica_n20",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729140 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"c",
[junit4] 2> "core":"withShardField_c_replica_n22",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729144 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"c",
[junit4] 2> "core":"withShardField_c_replica_n24",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56555/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729147 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"c",
[junit4] 2> "core":"withShardField_c_replica_n26",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729151 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"c",
[junit4] 2> "core":"withShardField_c_replica_n28",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729154 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"d",
[junit4] 2> "core":"withShardField_d_replica_n30",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729158 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"d",
[junit4] 2> "core":"withShardField_d_replica_n32",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56555/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729161 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"d",
[junit4] 2> "core":"withShardField_d_replica_n34",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56558/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729164 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"d",
[junit4] 2> "core":"withShardField_d_replica_n36",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56561/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729168 INFO (OverseerStateUpdate-98922979022340106-127.0.0.1:56558_solr-n_0000000000) [n:127.0.0.1:56558_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"withShardField",
[junit4] 2> "shard":"d",
[junit4] 2> "core":"withShardField_d_replica_n38",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:56554/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2729384 INFO (qtp83404244-21074) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=withShardField_a_replica_n2&action=CREATE&numShards=4&collection=withShardField&shard=a&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729391 INFO (qtp843186363-21055) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node17&collection.configName=conf&newCollection=true&name=withShardField_b_replica_n14&action=CREATE&numShards=4&collection=withShardField&shard=b&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729403 INFO (qtp843186363-21052) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node25&collection.configName=conf&newCollection=true&name=withShardField_c_replica_n22&action=CREATE&numShards=4&collection=withShardField&shard=c&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729406 INFO (qtp843186363-21050) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node33&collection.configName=conf&newCollection=true&name=withShardField_d_replica_n30&action=CREATE&numShards=4&collection=withShardField&shard=d&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729406 INFO (qtp83404244-21069) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node29&collection.configName=conf&newCollection=true&name=withShardField_c_replica_n26&action=CREATE&numShards=4&collection=withShardField&shard=c&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729412 INFO (qtp83404244-21072) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node37&collection.configName=conf&newCollection=true&name=withShardField_d_replica_n34&action=CREATE&numShards=4&collection=withShardField&shard=d&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729414 INFO (qtp83404244-21071) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node13&collection.configName=conf&newCollection=true&name=withShardField_b_replica_n10&action=CREATE&numShards=4&collection=withShardField&shard=b&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729416 INFO (qtp83404244-21070) [n:127.0.0.1:56558_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node21&collection.configName=conf&newCollection=true&name=withShardField_b_replica_n18&action=CREATE&numShards=4&collection=withShardField&shard=b&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2729417 INFO (qtp843186363-21048) [n:127.0.0.1:56554_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName
[...truncated too long message...]
core-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-core-api-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-core-avl-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-core-shared-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-i18n-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptor-kerberos-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-admin-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-authn-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-authz-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-changelog-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-collective-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-event-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-exception-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-journal-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-normalization-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-operational-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-referral-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-schema-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-subtree-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-interceptors-trigger-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-jdbm-partition-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-jdbm1-2.0.0-M2.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-kerberos-codec-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-ldif-partition-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-mavibot-partition-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-protocol-kerberos-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-protocol-ldap-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-protocol-shared-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/apacheds-xdbm-partition-2.0.0-M15.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/api-all-1.0.0-M20.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/bcprov-jdk15-1.45.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/byte-buddy-1.6.2.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/commons-collections-3.2.2.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/commons-math3-3.6.1.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/ehcache-core-2.4.4.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/hadoop-common-2.7.4-tests.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/hadoop-hdfs-2.7.4-tests.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/hadoop-minikdc-2.7.4.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/htrace-core-3.2.0-incubating.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/jersey-core-1.9.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/jersey-server-1.9.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/jetty-6.1.26.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/jetty-sslengine-6.1.26.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/jetty-util-6.1.26.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/mina-core-2.0.0-M5.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/mockito-core-2.6.2.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/netty-all-4.0.36.Final.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/core/test-lib/objenesis-2.5.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build/analysis/icu/lucene-analyzers-icu-7.2.0-SNAPSHOT.jar:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/contrib/solr-analysis-extras/classes/java:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build/queryparser/classes/test:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build/backward-codecs/classes/test:/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/contrib/analysis-extras/lib/icu4j-59.1.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/Users/jenkins/.ant/lib/ivy-2.3.0.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_144.jdk/Contents/Home/lib/tools.jar:/Users/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.5.3.jar com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20171031_092905_1575504524047590430819.events @/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20171031_092905_1576233902521393578675.suites -stdin
[junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. See process stdout at: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20171031_092905_1572242955450279347941.sysout
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1519)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:126)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:982)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:979)
[junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] at java.lang.Thread.run(Thread.java:748)
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:826: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:770: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:59: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build.xml:262: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/common-build.xml:556: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:1494: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:1021: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. See process stdout at: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20171031_092905_1572242955450279347941.sysout
Total time: 101 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-7.x-MacOSX (64bit/jdk1.8.0) - Build # 274 -
Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/274/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly
Error Message:
Unexpected number of elements in the group for intGSF: 5
Stack Trace:
java.lang.AssertionError: Unexpected number of elements in the group for intGSF: 5
at __randomizedtesting.SeedInfo.seed([49D8A617CDE62F4D:D263C84F80BE1D13]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.DocValuesNotIndexedTest.testGroupingDVOnly(DocValuesNotIndexedTest.java:377)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13242 lines...]
[junit4] Suite: org.apache.solr.cloud.DocValuesNotIndexedTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/init-core-data-001
[junit4] 2> 2578894 WARN (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 2578894 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2578898 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 2578899 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2578900 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001
[junit4] 2> 2578900 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2578900 INFO (Thread-5734) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2578900 INFO (Thread-5734) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2578903 ERROR (Thread-5734) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 2579005 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:55121
[junit4] 2> 2579022 INFO (jetty-launcher-6530-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2579022 INFO (jetty-launcher-6530-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2579024 INFO (jetty-launcher-6530-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1c56d1bf{/solr,null,AVAILABLE}
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5b61ce1f{/solr,null,AVAILABLE}
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6a350772{SSL,[ssl, http/1.1]}{127.0.0.1:55123}
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.e.j.s.Server Started @2582942ms
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=55123}
[junit4] 2> 2579025 ERROR (jetty-launcher-6530-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d41054f{SSL,[ssl, http/1.1]}{127.0.0.1:55124}
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.e.j.s.Server Started @2582942ms
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=55124}
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T18:25:45.486Z
[junit4] 2> 2579025 ERROR (jetty-launcher-6530-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.2.0
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2579025 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2579026 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-31T18:25:45.487Z
[junit4] 2> 2579027 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2579028 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2579037 INFO (jetty-launcher-6530-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:55121/solr
[junit4] 2> 2579037 INFO (jetty-launcher-6530-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:55121/solr
[junit4] 2> 2579173 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2579173 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2579174 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:55123_solr
[junit4] 2> 2579175 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55124_solr
[junit4] 2> 2579176 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.c.Overseer Overseer (id=98924910697709573-127.0.0.1:55123_solr-n_0000000000) starting
[junit4] 2> 2579177 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2579178 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2579195 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55123_solr
[junit4] 2> 2579198 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2579198 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2579260 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579266 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579266 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579267 INFO (jetty-launcher-6530-thread-2) [n:127.0.0.1:55124_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/.
[junit4] 2> 2579279 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579285 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579286 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2579287 INFO (jetty-launcher-6530-thread-1) [n:127.0.0.1:55123_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/.
[junit4] 2> 2579309 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2579310 INFO (SUITE-DocValuesNotIndexedTest-seed#[49D8A617CDE62F4D]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:55121/solr ready
[junit4] 2> 2579327 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2579330 INFO (OverseerThreadFactory-12371-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.CreateCollectionCmd Create collection dv_coll
[junit4] 2> 2579446 INFO (OverseerStateUpdate-98924910697709573-127.0.0.1:55123_solr-n_0000000000) [n:127.0.0.1:55123_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"dv_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:55124/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2579453 INFO (OverseerStateUpdate-98924910697709573-127.0.0.1:55123_solr-n_0000000000) [n:127.0.0.1:55123_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"dv_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:55123/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2579460 INFO (OverseerStateUpdate-98924910697709573-127.0.0.1:55123_solr-n_0000000000) [n:127.0.0.1:55123_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard3",
[junit4] 2> "core":"dv_coll_shard3_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:55124/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2579467 INFO (OverseerStateUpdate-98924910697709573-127.0.0.1:55123_solr-n_0000000000) [n:127.0.0.1:55123_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"dv_coll",
[junit4] 2> "shard":"shard4",
[junit4] 2> "core":"dv_coll_shard4_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:55123/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2579696 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica_n2&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2579697 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2579698 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica_n6&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2579712 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica_n1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2579713 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2579717 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica_n4&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2579828 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2579828 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2579829 INFO (zkCallback-6542-thread-2-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2579829 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2580749 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2580752 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2580754 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2580757 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2580788 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.IndexSchema [dv_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2580790 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.IndexSchema [dv_coll_shard3_replica_n4] Schema name=minimal
[junit4] 2> 2580792 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2580795 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2580795 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard3_replica_n4' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2580795 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2580796 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard1_replica_n1' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2580796 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.core.dv_coll.shard3.replica_n4' (registry 'solr.core.dv_coll.shard3.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2580796 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2580796 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.core.dv_coll.shard1.replica_n1' (registry 'solr.core.dv_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2580796 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [[dv_coll_shard3_replica_n4] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/dv_coll_shard3_replica_n4], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/./dv_coll_shard3_replica_n4/data/]
[junit4] 2> 2580796 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2580797 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [[dv_coll_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/dv_coll_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/./dv_coll_shard1_replica_n1/data/]
[junit4] 2> 2580797 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.IndexSchema [dv_coll_shard4_replica_n6] Schema name=minimal
[junit4] 2> 2580801 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2580801 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard2_replica_n2' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2580801 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2580801 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'dv_coll_shard4_replica_n6' using configuration from collection dv_coll, trusted=true
[junit4] 2> 2580801 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.core.dv_coll.shard2.replica_n2' (registry 'solr.core.dv_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2580802 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2580802 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [[dv_coll_shard2_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/dv_coll_shard2_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/./dv_coll_shard2_replica_n2/data/]
[junit4] 2> 2580802 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.core.dv_coll.shard4.replica_n6' (registry 'solr.core.dv_coll.shard4.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2580803 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2580803 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore [[dv_coll_shard4_replica_n6] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/dv_coll_shard4_replica_n6], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/./dv_coll_shard4_replica_n6/data/]
[junit4] 2> 2580899 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2580899 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2580900 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2580900 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2580902 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f6d45bd[dv_coll_shard2_replica_n2] main]
[junit4] 2> 2580904 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2580904 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2580904 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2580904 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2580904 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2580905 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2580905 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2580905 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2580905 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2580905 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798573263650816
[junit4] 2> 2580906 INFO (searcherExecutor-12378-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard2_replica_n2 s:shard2 c:dv_coll r:core_node5) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] Registered new searcher Searcher@5f6d45bd[dv_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2580910 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2580911 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2580911 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/
[junit4] 2> 2580911 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2580911 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/ has no replicas
[junit4] 2> 2580911 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2580912 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2580912 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2580914 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2580914 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2580915 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/ shard2
[junit4] 2> 2580915 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2580915 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2580916 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@5167734b[dv_coll_shard4_replica_n6] main]
[junit4] 2> 2580916 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ce741f0[dv_coll_shard1_replica_n1] main]
[junit4] 2> 2580917 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2580917 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2580917 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2580918 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2580917 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2580918 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2580918 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2580918 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2580918 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2580919 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2580919 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2580919 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798573278330880
[junit4] 2> 2580919 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2580920 INFO (searcherExecutor-12379-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard4_replica_n6 s:shard4 c:dv_coll r:core_node8) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore [dv_coll_shard4_replica_n6] Registered new searcher Searcher@5167734b[dv_coll_shard4_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2580920 INFO (searcherExecutor-12377-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard1_replica_n1 s:shard1 c:dv_coll r:core_node3) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] Registered new searcher Searcher@6ce741f0[dv_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2580920 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798573279379456
[junit4] 2> 2580921 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@55e8a1b[dv_coll_shard3_replica_n4] main]
[junit4] 2> 2580924 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2580924 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2580924 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/
[junit4] 2> 2580925 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2580925 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SyncStrategy https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/ has no replicas
[junit4] 2> 2580925 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2580925 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2580925 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2580925 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2580925 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:55124/solr/dv_coll_shard1_replica_n1/
[junit4] 2> 2580925 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2580925 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:55124/solr/dv_coll_shard1_replica_n1/ has no replicas
[junit4] 2> 2580926 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2580926 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2580926 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2580927 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 2580928 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/ shard4
[junit4] 2> 2580929 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:55124/solr/dv_coll_shard1_replica_n1/ shard1
[junit4] 2> 2580930 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2580930 INFO (searcherExecutor-12376-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard3_replica_n4 s:shard3 c:dv_coll r:core_node7) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [dv_coll_shard3_replica_n4] Registered new searcher Searcher@55e8a1b[dv_coll_shard3_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2580931 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798573290913792
[junit4] 2> 2580935 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2580935 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2580936 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:55124/solr/dv_coll_shard3_replica_n4/
[junit4] 2> 2580936 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2580936 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SyncStrategy https://127.0.0.1:55124/solr/dv_coll_shard3_replica_n4/ has no replicas
[junit4] 2> 2580936 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2580940 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:55124/solr/dv_coll_shard3_replica_n4/ shard3
[junit4] 2> 2581045 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581045 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581045 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581045 INFO (zkCallback-6542-thread-2-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581055 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2581058 INFO (qtp1561373918-28669) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf1&newCollection=true&name=dv_coll_shard3_replica_n4&action=CREATE&numShards=4&collection=dv_coll&shard=shard3&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1341
[junit4] 2> 2581090 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2581094 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf1&newCollection=true&name=dv_coll_shard2_replica_n2&action=CREATE&numShards=4&collection=dv_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1398
[junit4] 2> 2581095 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2581095 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2581101 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=dv_coll_shard1_replica_n1&action=CREATE&numShards=4&collection=dv_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1389
[junit4] 2> 2581102 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf1&newCollection=true&name=dv_coll_shard4_replica_n6&action=CREATE&numShards=4&collection=dv_coll&shard=shard4&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1403
[junit4] 2> 2581108 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2581212 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581212 INFO (zkCallback-6542-thread-2-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581212 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581212 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/dv_coll/state.json] for collection [dv_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2581334 INFO (OverseerCollectionConfigSetProcessor-98924910697709573-127.0.0.1:55123_solr-n_0000000000) [n:127.0.0.1:55123_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2582109 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf1&maxShardsPerNode=2&name=dv_coll&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2} status=0 QTime=2782
[junit4] 2> 2582131 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SchemaManager managed schema loaded . version : 0
[junit4] 2> 2582141 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2582146 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582156 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.ZkController Persisted config data to node /configs/conf1/managed-schema
[junit4] 2> 2582156 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2582156 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2582156 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2582156 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader A schema change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/configs/conf1/managed-schema, has occurred - updating schema from ZooKeeper ...
[junit4] 2> 2582157 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 2582157 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 2582158 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema [dv_coll_shard4_replica_n6] Schema name=minimal
[junit4] 2> 2582159 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema [dv_coll_shard3_replica_n4] Schema name=minimal
[junit4] 2> 2582161 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582161 INFO (zkCallback-6542-thread-1-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 4 ms
[junit4] 2> 2582161 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 2582162 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582162 INFO (zkCallback-6541-thread-1-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 4 ms
[junit4] 2> 2582163 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema [dv_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2582164 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard2_replica_n2
[junit4] 2> 2582164 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.c.SolrCore config update listener called for core dv_coll_shard1_replica_n1
[junit4] 2> 2582166 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582166 INFO (zkCallback-6542-thread-3-processing-n:127.0.0.1:55123_solr) [n:127.0.0.1:55123_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 4 ms
[junit4] 2> 2582167 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.c.SolrCore core reload dv_coll_shard2_replica_n2
[junit4] 2> 2582168 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.c.SolrCore core reload dv_coll_shard1_replica_n1
[junit4] 2> 2582174 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2582174 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2582180 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema [dv_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2582180 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2582183 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582183 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard1_replica_n1' using configuration from collection dv_coll
[junit4] 2> 2582183 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582183 INFO (Thread-5753) [n:127.0.0.1:55123_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard2_replica_n2' using configuration from collection dv_coll
[junit4] 2> 2582218 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55123.solr.core.dv_coll.shard2.replica_n2' (registry 'solr.core.dv_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2582218 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [[dv_coll_shard2_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/dv_coll_shard2_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node1/./dv_coll_shard2_replica_n2/data/]
[junit4] 2> 2582222 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.core.dv_coll.shard1.replica_n1' (registry 'solr.core.dv_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2582222 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [[dv_coll_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/dv_coll_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/./dv_coll_shard1_replica_n1/data/]
[junit4] 2> 2582266 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2582266 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2582267 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d19ea39[dv_coll_shard2_replica_n2] main]
[junit4] 2> 2582267 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2582267 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2582268 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2582268 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2582269 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2582269 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6b7e9fdf[dv_coll_shard1_replica_n1] main]
[junit4] 2> 2582269 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 2582270 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2582270 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798574694957056
[junit4] 2> 2582271 INFO (searcherExecutor-12396-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard2_replica_n2 s:shard2 c:dv_coll r:core_node5) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] Registered new searcher Searcher@5d19ea39[dv_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582272 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2582272 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 2582272 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@624e139[dv_coll_shard2_replica_n2] main]
[junit4] 2> 2582272 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2582272 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@581e5786
[junit4] 2> 2582272 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf1/managed-schema
[junit4] 2> 2582272 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.dv_coll.shard2.replica_n2, tag=1478383494
[junit4] 2> 2582272 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3cb9033e: rootName = solr_55123, domain = solr.core.dv_coll.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.dv_coll.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@43eb2abc
[junit4] 2> 2582273 INFO (searcherExecutor-12396-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard2_replica_n2 s:shard2 c:dv_coll r:core_node5) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] Registered new searcher Searcher@624e139[dv_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582274 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 1 is already the latest
[junit4] 2> 2582274 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2582274 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1582798574699151360
[junit4] 2> 2582276 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.dv_coll.shard2.leader, tag=1478383494
[junit4] 2> 2582277 INFO (searcherExecutor-12397-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard1_replica_n1 s:shard1 c:dv_coll r:core_node3) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] Registered new searcher Searcher@6b7e9fdf[dv_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582278 INFO (Thread-5753) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore config update listener called for core dv_coll_shard4_replica_n6
[junit4] 2> 2582279 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 2582279 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@31662ade[dv_coll_shard1_replica_n1] main]
[junit4] 2> 2582281 INFO (searcherExecutor-12397-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard1_replica_n1 s:shard1 c:dv_coll r:core_node3) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] Registered new searcher Searcher@31662ade[dv_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582281 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 1 from ZooKeeper
[junit4] 2> 2582286 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2582286 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 3 replicas to apply schema update version 1 for collection dv_coll
[junit4] 2> 2582288 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 2582290 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582290 INFO (zkCallback-6541-thread-2-processing-n:127.0.0.1:55124_solr) [n:127.0.0.1:55124_solr ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 9 ms
[junit4] 2> 2582292 INFO (qtp1463988329-28658) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.S.Request [dv_coll_shard2_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2582294 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema [dv_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2582296 INFO (qtp1561373918-28674) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.S.Request [dv_coll_shard3_replica_n4] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2582297 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2582297 INFO (Thread-5754) [n:127.0.0.1:55124_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'dv_coll_shard1_replica_n1' using configuration from collection dv_coll
[junit4] 2> 2582300 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.S.Request [dv_coll_shard4_replica_n6] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2582301 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Took 21.0ms for 3 replicas to apply schema update version 1 for collection dv_coll
[junit4] 2> 2582301 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.S.Request [dv_coll_shard1_replica_n1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=172
[junit4] 2> 2582302 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@4e56cd93
[junit4] 2> 2582302 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.dv_coll.shard1.replica_n1, tag=1314311571
[junit4] 2> 2582302 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7dff7106: rootName = solr_55124, domain = solr.core.dv_coll.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.dv_coll.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@35c44f6b
[junit4] 2> 2582310 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.dv_coll.shard1.leader, tag=1314311571
[junit4] 2> 2582329 INFO (TEST-DocValuesNotIndexedTest.testGroupingDocAbsent-seed#[49D8A617CDE62F4D]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testGroupingDocAbsent
[junit4] 2> 2582333 INFO (Thread-5754) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55124.solr.core.dv_coll.shard1.replica_n1' (registry 'solr.core.dv_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d195199
[junit4] 2> 2582334 INFO (Thread-5754) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [[dv_coll_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/dv_coll_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001/tempDir-001/node2/./dv_coll_shard1_replica_n1/data/]
[junit4] 2> 2582337 INFO (qtp1463988329-28658) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/&wt=javabin&version=2}{deleteByQuery=*:* (-1582798574761017344)} 0 4
[junit4] 2> 2582338 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/&wt=javabin&version=2}{deleteByQuery=*:* (-1582798574762065920)} 0 4
[junit4] 2> 2582338 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica_n4] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/&wt=javabin&version=2}{deleteByQuery=*:* (-1582798574761017344)} 0 5
[junit4] 2> 2582338 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica_n6] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1582798574758920192)} 0 8
[junit4] 2> 2582339 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574767308800,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582340 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2582341 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582341 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574769405952,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582342 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2582342 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582342 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 2582342 INFO (qtp1561373918-28665) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574770454528,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582342 INFO (qtp1561373918-28665) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2582343 INFO (qtp1561373918-28673) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2582344 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574772551680,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582344 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2582347 INFO (qtp1561373918-28665) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@713445e3[dv_coll_shard3_replica_n4] main]
[junit4] 2> 2582347 INFO (qtp1561373918-28665) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582348 INFO (searcherExecutor-12376-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard3_replica_n4 s:shard3 c:dv_coll r:core_node7) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [dv_coll_shard3_replica_n4] Registered new searcher Searcher@713445e3[dv_coll_shard3_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582348 INFO (qtp1561373918-28665) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica_n4] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 6
[junit4] 2> 2582349 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@4a24a5f6[dv_coll_shard4_replica_n6] main]
[junit4] 2> 2582349 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582350 INFO (searcherExecutor-12379-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard4_replica_n6 s:shard4 c:dv_coll r:core_node8) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.SolrCore [dv_coll_shard4_replica_n6] Registered new searcher Searcher@4a24a5f6[dv_coll_shard4_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2582350 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 2582350 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=dv_coll:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 11
[junit4] 2> 2582354 INFO (qtp1463988329-28660) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=dv_coll:4&wt=javabin&version=2}{add=[4 (1582798574781988864)]} 0 1
[junit4] 2> 2582356 INFO (qtp1561373918-28672) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=dv_coll:4&wt=javabin&version=2}{add=[1 (1582798574784086016)]} 0 3
[junit4] 2> 2582357 INFO (qtp1561373918-28674) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica_n4] webapp=/solr path=/update params={_stateVer_=dv_coll:4&wt=javabin&version=2}{add=[2 (1582798574784086016), 3 (1582798574786183168)]} 0 2
[junit4] 2> 2582359 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574788280320,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582359 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6b0acb6c commitCommandVersion:1582798574788280320
[junit4] 2> 2582359 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574788280320,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582359 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2582360 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582360 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574789328896,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582360 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@579f7870 commitCommandVersion:1582798574789328896
[junit4] 2> 2582360 INFO (qtp1463988329-28667) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard4_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 2582360 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1582798574789328896,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2582360 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5fa53d30 commitCommandVersion:1582798574789328896
[junit4] 2> 2582364 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@77564d21[dv_coll_shard2_replica_n2] main]
[junit4] 2> 2582365 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582365 INFO (searcherExecutor-12396-thread-1-processing-n:127.0.0.1:55123_solr x:dv_coll_shard2_replica_n2 s:shard2 c:dv_coll r:core_node5) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.SolrCore [dv_coll_shard2_replica_n2] Registered new searcher Searcher@77564d21[dv_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1)))}
[junit4] 2> 2582366 INFO (qtp1463988329-28661) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 2582368 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@2553c157[dv_coll_shard3_replica_n4] main]
[junit4] 2> 2582368 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582369 INFO (searcherExecutor-12376-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard3_replica_n4 s:shard3 c:dv_coll r:core_node7) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.c.SolrCore [dv_coll_shard3_replica_n4] Registered new searcher Searcher@2553c157[dv_coll_shard3_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C2)))}
[junit4] 2> 2582369 INFO (qtp1561373918-28671) [n:127.0.0.1:55124_solr c:dv_coll s:shard3 r:core_node7 x:dv_coll_shard3_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard3_replica_n4] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 8
[junit4] 2> 2582369 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@79dc597[dv_coll_shard1_replica_n1] main]
[junit4] 2> 2582370 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2582371 INFO (searcherExecutor-12397-thread-1-processing-n:127.0.0.1:55124_solr x:dv_coll_shard1_replica_n1 s:shard1 c:dv_coll r:core_node3) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.c.SolrCore [dv_coll_shard1_replica_n1] Registered new searcher Searcher@79dc597[dv_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):C1)))}
[junit4] 2> 2582371 INFO (qtp1561373918-28668) [n:127.0.0.1:55124_solr c:dv_coll s:shard1 r:core_node3 x:dv_coll_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:55123/solr/dv_coll_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 12
[junit4] 2> 2582372 INFO (qtp1463988329-28660) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [dv_coll_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=dv_coll:4&commit=true&wt=javabin&version=2}{commit=} 0 13
[junit4] 2> 2582377 INFO (qtp1463988329-28663) [n:127.0.0.1:55123_solr c:dv_coll s:shard4 r:core_node8 x:dv_coll_shard4_replica_n6] o.a.s.c.S.Request [dv_coll_shard4_replica_n6] webapp=/solr path=/select params={df=text&group.distributed.first=true&distrib=false&_stateVer_=dv_coll:4&fl=id,score&shards.purpose=2048&start=0&shard.url=https://127.0.0.1:55123/solr/dv_coll_shard4_replica_n6/&rows=10&version=2&q=*:*&NOW=1509474348833&isShard=true&wt=javabin&group.field=intGSF&group=true} status=0 QTime=4
[junit4] 2> 2582377 INFO (qtp1463988329-28662) [n:127.0.0.1:55123_solr c:dv_coll s:shard2 r:core_node5 x:dv_coll_shard2_replica_n2] o.a.s.c.S.Request [dv_coll_shard2_replica_n2] webap
[...truncated too long message...]
] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 2 /solr/configs/conf1/managed-schema
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.DocValuesNotIndexedTest_49D8A617CDE62F4D-001
[junit4] 2> Oct 31, 2017 6:25:49 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=Memory)}, docValues:{floatField=DocValuesFormat(name=Direct), doubleField=DocValuesFormat(name=Lucene70), intFieldMulti=DocValuesFormat(name=Asserting), boolFieldMulti=DocValuesFormat(name=Lucene70), longFieldMulti=DocValuesFormat(name=Memory), floatGSL=DocValuesFormat(name=Direct), intField=DocValuesFormat(name=Memory), boolField=DocValuesFormat(name=Direct), stringFieldMulti=DocValuesFormat(name=Direct), dateFieldMulti=DocValuesFormat(name=Lucene70), longGSF=DocValuesFormat(name=Asserting), doubleFieldMulti=DocValuesFormat(name=Direct), stringGSL=DocValuesFormat(name=Memory), doubleGSF=DocValuesFormat(name=Lucene70), doubleGSL=DocValuesFormat(name=Memory), stringGSF=DocValuesFormat(name=Lucene70), intGSL=DocValuesFormat(name=Lucene70), longField=DocValuesFormat(name=Asserting), dateField=DocValuesFormat(name=Asserting), dateGSF=DocValuesFormat(name=Direct), boolGSF=DocValuesFormat(name=Direct), longGSL=DocValuesFormat(name=Direct), boolGSL=DocValuesFormat(name=Asserting), floatFieldMulti=DocValuesFormat(name=Memory), floatGSF=DocValuesFormat(name=Asserting), dateGSL=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Direct), intGSF=DocValuesFormat(name=Memory), stringField=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=329, maxMBSortInHeap=7.495083941063396, sim=RandomSimilarity(queryNorm=true): {}, locale=fr-CH, timezone=Indian/Kerguelen
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=283136088,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [LeaderElectionTest, SpellCheckComponentTest, SolrCmdDistributorTest, TestHdfsUpdateLog, UninvertDocValuesMergePolicyTest, TestExpandComponent, AddReplicaTest, ShowFileRequestHandlerTest, UtilsToolTest, TestOmitPositions, TestAtomicUpdateErrorCases, SortByFunctionTest, CircularListTest, TestSolrCloudWithKerberosAlt, TestSchemaNameResource, DateFieldTest, TestSchemaSimilarityResource, TestCloudInspectUtil, ChaosMonkeyNothingIsSafeTest, TestBinaryField, SuggesterTSTTest, BasicAuthIntegrationTest, TestLeaderInitiatedRecoveryThread, JSONWriterTest, TestQueryWrapperFilter, TestNumericRangeQuery32, BinaryUpdateRequestHandlerTest, TestRawTransformer, CurrencyFieldTypeTest, TestInfoStreamLogging, DirectUpdateHandlerTest, HdfsLockFactoryTest, DistributedVersionInfoTest, CoreSorterTest, TestReplicationHandler, TestHdfsBackupRestoreCore, TestHighlightDedupGrouping, LeaderInitiatedRecoveryOnShardRestartTest, TestRangeQuery, OutputWriterTest, SuggesterTest, CollectionReloadTest, QueryResultKeyTest, SuggesterFSTTest, TestReqParamsAPI, DistribCursorPagingTest, SubstringBytesRefFilterTest, UUIDFieldTest, CdcrVersionReplicationTest, PathHierarchyTokenizerFactoryTest, TestExactStatsCache, DistributedTermsComponentTest, ZkControllerTest, OutOfBoxZkACLAndCredentialsProvidersTest, ReplaceNodeTest, SolrTestCaseJ4Test, TestSQLHandler, AtomicUpdateProcessorFactoryTest, TestNoOpRegenerator, TestBlobHandler, TestSchemalessBufferedUpdates, ParsingFieldUpdateProcessorsTest, SolrShardReporterTest, TestAuthenticationFramework, HdfsSyncSliceTest, TestTolerantSearch, RequestHandlersTest, MetricsHandlerTest, AssignBackwardCompatibilityTest, TestSolrQueryResponse, RequiredFieldsTest, BlockCacheTest, NumericFieldsTest, SpellCheckCollatorWithCollapseTest, MoveReplicaHDFSTest, IndexSchemaTest, TestLMDirichletSimilarityFactory, CdcrUpdateLogTest, OverseerRolesTest, TestFieldCacheVsDocValues, HdfsNNFailoverTest, TestSolrCLIRunExample, UUIDUpdateProcessorFallbackTest, DistributedQueryComponentOptimizationTest, TestDistribDocBasedVersion, TestCursorMarkWithoutUniqueKey, HLLUtilTest, TestStressCloudBlindAtomicUpdates, TestFieldCollectionResource, CdcrBootstrapTest, ShardSplitTest, TestSSLRandomization, TestClusterStateMutator, HdfsChaosMonkeySafeLeaderTest, TestNamedUpdateProcessors, TestCodecSupport, BlobRepositoryCloudTest, TestSkipOverseerOperations, SystemLogListenerTest, FastVectorHighlighterTest, DocValuesMissingTest, PeerSyncWithIndexFingerprintCachingTest, TestDynamicFieldCollectionResource, MissingSegmentRecoveryTest, TestXmlQParserPlugin, TestRandomFlRTGCloud, TestSubQueryTransformer, ClusterStateTest, HighlighterTest, TestEmbeddedSolrServerSchemaAPI, TestRequestForwarding, TestCustomSort, TestClusterProperties, TestLockTree, TestJsonFacets, SolrGangliaReporterTest, DistanceFunctionTest, TestGraphMLResponseWriter, TestJmxIntegration, TestRealTimeGet, CoreAdminCreateDiscoverTest, TestLegacyFieldReuse, DistributedFacetPivotLargeTest, PrimUtilsTest, SpatialHeatmapFacetsTest, AutoScalingHandlerTest, ScriptEngineTest, TestCollectionsAPIViaSolrCloudCluster, TestSha256AuthenticationProvider, TestXIncludeConfig, StatsComponentTest, VMParamsZkACLAndCredentialsProvidersTest, TestExclusionRuleCollectionAccess, TestAddFieldRealTimeGet, SolrRequestParserTest, TestLazyCores, TestQuerySenderListener, TestDistributedSearch, TestScoreJoinQPScore, BitVectorTest, ResponseLogComponentTest, CollectionsAPISolrJTest, TestUpdate, RuleEngineTest, DirectUpdateHandlerOptimizeTest, TestManagedResourceStorage, TestCSVResponseWriter, BufferStoreTest, BooleanFieldTest, DocExpirationUpdateProcessorFactoryTest, CloudMLTQParserTest, TestNonDefinedSimilarityFactory, TestNRTOpen, FullHLLTest, DistribJoinFromCollectionTest, MultiThreadedOCPTest, MinimalSchemaTest, TestSolrConfigHandler, TestSolrCoreParser, DeleteInactiveReplicaTest, RegexBoostProcessorTest, NodeLostTriggerTest, NoCacheHeaderTest, AddBlockUpdateTest, DefaultValueUpdateProcessorTest, TestTrieFacet, TestBulkSchemaAPI, SolrMetricReporterTest, DirectSolrConnectionTest, TestUnifiedSolrHighlighter, FacetPivotSmallTest, CdcrReplicationHandlerTest, TestWriterPerf, CleanupOldIndexTest, TestPayloadCheckQParserPlugin, HdfsRecoveryZkTest, TriggerIntegrationTest, TestExportWriter, RecoveryZkTest, TestNestedDocsSort, ClassificationUpdateProcessorFactoryTest, SolrJmxReporterCloudTest, DistributedExpandComponentTest, TestComplexPhraseLeadingWildcard, TestSubQueryTransformerDistrib, TestCollectionAPIs, UnloadDistributedZkTest, SyncSliceTest, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestRandomFaceting, ZkSolrClientTest, TestZkChroot, TestRandomDVFaceting, ZkCLITest, ShardRoutingCustomTest, TestFaceting, TestRecovery, TestHashPartitioner, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, TestStressReorder, TestJoin, TestReload, TestStressVersions, TestCoreContainer, TestSolr4Spatial, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, BasicFunctionalityTest, TestIndexSearcher, DistributedQueryElevationComponentTest, SimplePostToolTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, CoreAdminHandlerTest, TestFoldingMultitermQuery, TestTrie, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, TestWordDelimiterFilterFactory, QueryEqualityTest, TestSolrDeletionPolicy1, SolrInfoBeanTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestReversedWildcardFilterFactory, TestQueryTypes, PrimitiveFieldTypeTest, TermsComponentTest, XmlUpdateRequestHandlerTest, TestValueSourceCache, TestIndexingPerformance, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestCollationField, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, QueryParsingTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, PingRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, TestLFUCache, HighlighterConfigTest, UpdateParamsTest, AlternateDirectoryTest, TestSolrIndexConfig, TestQuerySenderNoQuery, CopyFieldTest, TestStressRecovery, TestSolrDeletionPolicy2, MultiTermTest, TestConfig, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestPhraseSuggestions, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestIBSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, PluginInfoTest, TestFastLRUCache, DateMathParserTest, PreAnalyzedFieldTest, TestSystemIdResolver, TestSuggestSpellingConverter, SpellingQueryConverterTest, RAMDirectoryFactoryTest, TestUtils, SliceStateTest, SystemInfoHandlerTest, DistributedMLTComponentTest, TestRTGBase, CursorPagingTest, TestCrossCoreJoin, TestSimpleTrackingShardHandler, TestLuceneIndexBackCompat, AsyncCallRequestStatusResponseTest, BaseCdcrDistributedZkTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, CloudExitableDirectoryReaderTest, CollectionTooManyReplicasTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteNodeTest, DeleteShardTest, DocValuesNotIndexedTest]
[junit4] Completed [524/746 (1!)] on J0 in 4.84s, 4 tests, 1 failure <<< FAILURES!
[...truncated 47994 lines...]