You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/07/18 21:56:47 UTC
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1977 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1977/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest.testBiDir
Error Message:
Captured an uncaught exception in thread: Thread[id=33044, name=cdcr-replicator-12099-thread-1, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=33044, name=cdcr-replicator-12099-thread-1, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
Caused by: java.lang.AssertionError: 1606364740387340288 != 1606364740384194560
at __randomizedtesting.SeedInfo.seed([8FF7A505CA5F3397]:0)
at org.apache.solr.update.CdcrUpdateLog$CdcrLogReader.forwardSeek(CdcrUpdateLog.java:611)
at org.apache.solr.handler.CdcrReplicator.run(CdcrReplicator.java:125)
at org.apache.solr.handler.CdcrReplicatorScheduler.lambda$null$0(CdcrReplicatorScheduler.java:81)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 14186 lines...]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/init-core-data-001
[junit4] 2> 3568691 INFO (SUITE-CdcrBidirectionalTest-seed#[8FF7A505CA5F3397]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3568691 INFO (SUITE-CdcrBidirectionalTest-seed#[8FF7A505CA5F3397]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 3568691 INFO (SUITE-CdcrBidirectionalTest-seed#[8FF7A505CA5F3397]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3568693 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBiDir
[junit4] 2> 3568693 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001
[junit4] 2> 3568693 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3568693 INFO (Thread-6464) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3568693 INFO (Thread-6464) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3568696 ERROR (Thread-6464) [ ] 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> 3568798 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.ZkTestServer start zk server on port:33287
[junit4] 2> 3568800 INFO (zkConnectionManagerCallback-9904-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3568804 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 3568805 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3568805 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3568805 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 3568805 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6edaed9c{/solr,null,AVAILABLE}
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@11ff6c98{HTTP/1.1,[http/1.1]}{127.0.0.1:46660}
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.e.j.s.Server Started @3570696ms
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46660}
[junit4] 2> 3568806 ERROR (jetty-launcher-9901-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3568806 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-18T21:19:35.979Z
[junit4] 2> 3568807 INFO (zkConnectionManagerCallback-9906-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3568808 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3569460 INFO (jetty-launcher-9901-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33287/solr
[junit4] 2> 3569462 INFO (zkConnectionManagerCallback-9910-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569465 INFO (zkConnectionManagerCallback-9912-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569645 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46660_solr
[junit4] 2> 3569647 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.c.Overseer Overseer (id=72530618166411267-127.0.0.1:46660_solr-n_0000000000) starting
[junit4] 2> 3569666 INFO (zkConnectionManagerCallback-9919-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569669 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33287/solr ready
[junit4] 2> 3569670 INFO (OverseerStateUpdate-72530618166411267-127.0.0.1:46660_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46660_solr
[junit4] 2> 3569670 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46660_solr
[junit4] 2> 3569672 INFO (zkCallback-9918-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3569674 INFO (OverseerStateUpdate-72530618166411267-127.0.0.1:46660_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3569696 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3569732 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46660.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3569739 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46660.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3569739 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46660.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3569740 INFO (jetty-launcher-9901-thread-1) [n:127.0.0.1:46660_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001/node1/.
[junit4] 2> 3569756 INFO (zkConnectionManagerCallback-9922-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569760 INFO (zkConnectionManagerCallback-9925-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569762 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001
[junit4] 2> 3569762 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3569762 INFO (Thread-6474) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3569762 INFO (Thread-6474) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3569765 ERROR (Thread-6474) [ ] 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> 3569863 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.ZkTestServer start zk server on port:51131
[junit4] 2> 3569866 INFO (zkConnectionManagerCallback-9929-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569870 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 3569871 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 3569871 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 3569871 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@510446b3{/solr,null,AVAILABLE}
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@49b7c6dc{HTTP/1.1,[http/1.1]}{127.0.0.1:45952}
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.e.j.s.Server Started @3571762ms
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45952}
[junit4] 2> 3569872 ERROR (jetty-launcher-9926-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3569872 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-18T21:19:37.045Z
[junit4] 2> 3569874 INFO (zkConnectionManagerCallback-9931-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3569875 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3570498 INFO (jetty-launcher-9926-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51131/solr
[junit4] 2> 3570499 INFO (zkConnectionManagerCallback-9935-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570502 INFO (zkConnectionManagerCallback-9937-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570657 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45952_solr
[junit4] 2> 3570659 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.c.Overseer Overseer (id=72530618236534787-127.0.0.1:45952_solr-n_0000000000) starting
[junit4] 2> 3570671 INFO (zkConnectionManagerCallback-9944-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570674 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:51131/solr ready
[junit4] 2> 3570675 INFO (OverseerStateUpdate-72530618236534787-127.0.0.1:45952_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:45952_solr
[junit4] 2> 3570676 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45952_solr
[junit4] 2> 3570678 INFO (zkCallback-9943-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3570681 INFO (zkCallback-9936-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3570707 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 3570722 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45952.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3570729 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45952.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3570729 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45952.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3570730 INFO (jetty-launcher-9926-thread-1) [n:127.0.0.1:45952_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001/node1/.
[junit4] 2> 3570752 INFO (zkConnectionManagerCallback-9947-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570756 INFO (zkConnectionManagerCallback-9950-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570758 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.CdcrBidirectionalTest cluster2 zkHost = 127.0.0.1:33287/solr
[junit4] 2> 3570758 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.CdcrBidirectionalTest cluster1 zkHost = 127.0.0.1:51131/solr
[junit4] 2> 3570760 INFO (zkConnectionManagerCallback-9952-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570767 INFO (zkConnectionManagerCallback-9956-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3570769 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3570771 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:51131/solr ready
[junit4] 2> 3570775 INFO (qtp2135776655-32909) [n:127.0.0.1:45952_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=cdcr-cluster1&maxShardsPerNode=2&name=cdcr-cluster1&nrtReplicas=1&action=CREATE&numShards=2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3570780 INFO (OverseerThreadFactory-12060-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection cdcr-cluster1
[junit4] 2> 3570894 INFO (OverseerStateUpdate-72530618236534787-127.0.0.1:45952_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-cluster1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"cdcr-cluster1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45952/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3570898 INFO (OverseerStateUpdate-72530618236534787-127.0.0.1:45952_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-cluster1",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"cdcr-cluster1_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45952/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3571104 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-cluster1&newCollection=true&collection=cdcr-cluster1&version=2&replicaType=NRT&coreNodeName=core_node3&name=cdcr-cluster1_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 3571104 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr x:cdcr-cluster1_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-cluster1&newCollection=true&collection=cdcr-cluster1&version=2&replicaType=NRT&coreNodeName=core_node4&name=cdcr-cluster1_shard2_replica_n2&action=CREATE&numShards=2&shard=shard2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 3571104 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3572126 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3572127 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3572134 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.IndexSchema [cdcr-cluster1_shard2_replica_n2] Schema name=minimal
[junit4] 2> 3572134 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-cluster1_shard1_replica_n1] Schema name=minimal
[junit4] 2> 3572136 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3572136 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-cluster1_shard1_replica_n1' using configuration from collection cdcr-cluster1, trusted=true
[junit4] 2> 3572136 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3572136 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-cluster1_shard2_replica_n2' using configuration from collection cdcr-cluster1, trusted=true
[junit4] 2> 3572136 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45952.solr.core.cdcr-cluster1.shard1.replica_n1' (registry 'solr.core.cdcr-cluster1.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3572136 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45952.solr.core.cdcr-cluster1.shard2.replica_n2' (registry 'solr.core.cdcr-cluster1.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3572149 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3572149 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3572149 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SolrCore [[cdcr-cluster1_shard2_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001/node1/cdcr-cluster1_shard2_replica_n2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001/node1/./cdcr-cluster1_shard2_replica_n2/data/]
[junit4] 2> 3572149 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-cluster1_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001/node1/cdcr-cluster1_shard1_replica_n1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster1-001/node1/./cdcr-cluster1_shard1_replica_n1/data/]
[junit4] 2> 3572426 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 3572426 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3572426 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 3572426 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3572427 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3572427 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3572427 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3572427 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3572427 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f7f6e74[cdcr-cluster1_shard2_replica_n2] main]
[junit4] 2> 3572431 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@d847327[cdcr-cluster1_shard1_replica_n1] main]
[junit4] 2> 3572432 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-cluster1
[junit4] 2> 3572432 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-cluster1
[junit4] 2> 3572433 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-cluster1
[junit4] 2> 3572433 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-cluster1
[junit4] 2> 3572433 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-cluster1/managed-schema
[junit4] 2> 3572433 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-cluster1/managed-schema
[junit4] 2> 3572434 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3572434 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3572435 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3572435 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3572444 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-cluster1/cdcr/state/buffer
[junit4] 2> 3572459 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-cluster1/cdcr/state/process
[junit4] 2> 3572488 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606364723581812736
[junit4] 2> 3572489 INFO (searcherExecutor-12065-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-cluster1_shard1_replica_n1] Registered new searcher Searcher@d847327[cdcr-cluster1_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3572488 INFO (searcherExecutor-12066-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard2_replica_n2 c:cdcr-cluster1 s:shard2 r:core_node4) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SolrCore [cdcr-cluster1_shard2_replica_n2] Registered new searcher Searcher@1f7f6e74[cdcr-cluster1_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3572488 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606364723581812736
[junit4] 2> 3572498 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster1/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 3572501 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster1/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 3572505 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3572506 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3572506 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/
[junit4] 2> 3572506 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3572506 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3572507 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:45952/solr/cdcr-cluster1_shard1_replica_n1/
[junit4] 2> 3572507 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3572507 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3572508 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SyncStrategy http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/ has no replicas
[junit4] 2> 3572508 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3572508 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:45952/solr/cdcr-cluster1_shard1_replica_n1/ has no replicas
[junit4] 2> 3572508 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3572513 INFO (zkCallback-9936-thread-1) [ ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-cluster1:shard1
[junit4] 2> 3572524 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45952/solr/cdcr-cluster1_shard1_replica_n1/ shard1
[junit4] 2> 3572527 INFO (zkCallback-9936-thread-1) [ ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-cluster1:shard2
[junit4] 2> 3572532 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/ shard2
[junit4] 2> 3572677 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3572680 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-cluster1&newCollection=true&collection=cdcr-cluster1&version=2&replicaType=NRT&coreNodeName=core_node3&name=cdcr-cluster1_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1577
[junit4] 2> 3572685 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3572687 INFO (qtp2135776655-32905) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-cluster1&newCollection=true&collection=cdcr-cluster1&version=2&replicaType=NRT&coreNodeName=core_node4&name=cdcr-cluster1_shard2_replica_n2&action=CREATE&numShards=2&shard=shard2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1584
[junit4] 2> 3572691 INFO (qtp2135776655-32909) [n:127.0.0.1:45952_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> 3572782 INFO (OverseerCollectionConfigSetProcessor-72530618236534787-127.0.0.1:45952_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 3572788 INFO (zkCallback-9936-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-cluster1/state.json] for collection [cdcr-cluster1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 3573692 INFO (qtp2135776655-32909) [n:127.0.0.1:45952_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=cdcr-cluster1&maxShardsPerNode=2&name=cdcr-cluster1&nrtReplicas=1&action=CREATE&numShards=2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2917
[junit4] 2> 3573694 INFO (zkConnectionManagerCallback-9960-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3573702 INFO (zkConnectionManagerCallback-9964-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3573704 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3573706 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33287/solr ready
[junit4] 2> 3573707 INFO (qtp284612327-32855) [n:127.0.0.1:46660_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=cdcr-cluster2&maxShardsPerNode=2&name=cdcr-cluster2&nrtReplicas=1&action=CREATE&numShards=2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3573710 INFO (OverseerThreadFactory-12047-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection cdcr-cluster2
[junit4] 2> 3573826 INFO (OverseerStateUpdate-72530618166411267-127.0.0.1:46660_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-cluster2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"cdcr-cluster2_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46660/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3573830 INFO (OverseerStateUpdate-72530618166411267-127.0.0.1:46660_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"cdcr-cluster2",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"cdcr-cluster2_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46660/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3574035 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-cluster2&newCollection=true&collection=cdcr-cluster2&version=2&replicaType=NRT&coreNodeName=core_node3&name=cdcr-cluster2_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 3574036 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3574036 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-cluster2&newCollection=true&collection=cdcr-cluster2&version=2&replicaType=NRT&coreNodeName=core_node4&name=cdcr-cluster2_shard2_replica_n2&action=CREATE&numShards=2&shard=shard2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin
[junit4] 2> 3575052 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3575054 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3575074 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.IndexSchema [cdcr-cluster2_shard1_replica_n1] Schema name=minimal
[junit4] 2> 3575075 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.IndexSchema [cdcr-cluster2_shard2_replica_n2] Schema name=minimal
[junit4] 2> 3575078 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3575078 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-cluster2_shard1_replica_n1' using configuration from collection cdcr-cluster2, trusted=true
[junit4] 2> 3575078 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3575078 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-cluster2_shard2_replica_n2' using configuration from collection cdcr-cluster2, trusted=true
[junit4] 2> 3575078 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46660.solr.core.cdcr-cluster2.shard1.replica_n1' (registry 'solr.core.cdcr-cluster2.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3575078 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46660.solr.core.cdcr-cluster2.shard2.replica_n2' (registry 'solr.core.cdcr-cluster2.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2a3ad523
[junit4] 2> 3575078 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3575078 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3575078 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SolrCore [[cdcr-cluster2_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001/node1/cdcr-cluster2_shard1_replica_n1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001/node1/./cdcr-cluster2_shard1_replica_n1/data/]
[junit4] 2> 3575079 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SolrCore [[cdcr-cluster2_shard2_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001/node1/cdcr-cluster2_shard2_replica_n2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.cdcr.CdcrBidirectionalTest_8FF7A505CA5F3397-001/cdcr-cluster2-001/node1/./cdcr-cluster2_shard2_replica_n2/data/]
[junit4] 2> 3575225 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 3575225 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3575226 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3575226 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3575227 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 3575227 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3575228 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@9735bd4[cdcr-cluster2_shard1_replica_n1] main]
[junit4] 2> 3575228 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3575228 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3575229 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-cluster2
[junit4] 2> 3575230 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@a45044f[cdcr-cluster2_shard2_replica_n2] main]
[junit4] 2> 3575230 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-cluster2
[junit4] 2> 3575230 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-cluster2/managed-schema
[junit4] 2> 3575231 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3575231 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-cluster2
[junit4] 2> 3575231 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3575231 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-cluster2
[junit4] 2> 3575232 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cdcr-cluster2/managed-schema
[junit4] 2> 3575232 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3575233 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3575236 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrBufferStateManager Created znode /collections/cdcr-cluster2/cdcr/state/buffer
[junit4] 2> 3575239 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrProcessStateManager Created znode /collections/cdcr-cluster2/cdcr/state/process
[junit4] 2> 3575242 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606364726469591040
[junit4] 2> 3575242 INFO (searcherExecutor-12077-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-cluster2_shard1_replica_n1] Registered new searcher Searcher@9735bd4[cdcr-cluster2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3575243 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606364726470639616
[junit4] 2> 3575244 INFO (searcherExecutor-12078-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SolrCore [cdcr-cluster2_shard2_replica_n2] Registered new searcher Searcher@a45044f[cdcr-cluster2_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3575255 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster2/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 3575258 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster2/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 3575261 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3575261 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3575261 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46660/solr/cdcr-cluster2_shard1_replica_n1/
[junit4] 2> 3575261 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3575262 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:46660/solr/cdcr-cluster2_shard1_replica_n1/ has no replicas
[junit4] 2> 3575262 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3575263 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3575263 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3575263 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46660/solr/cdcr-cluster2_shard2_replica_n2/
[junit4] 2> 3575264 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3575264 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SyncStrategy http://127.0.0.1:46660/solr/cdcr-cluster2_shard2_replica_n2/ has no replicas
[junit4] 2> 3575264 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3575266 INFO (zkCallback-9911-thread-1) [ ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-cluster2:shard1
[junit4] 2> 3575270 INFO (zkCallback-9911-thread-1) [ ] o.a.s.h.CdcrLeaderStateManager Received new leader state @ cdcr-cluster2:shard2
[junit4] 2> 3575273 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46660/solr/cdcr-cluster2_shard1_replica_n1/ shard1
[junit4] 2> 3575275 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46660/solr/cdcr-cluster2_shard2_replica_n2/ shard2
[junit4] 2> 3575428 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3575431 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 3575432 INFO (qtp284612327-32851) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-cluster2&newCollection=true&collection=cdcr-cluster2&version=2&replicaType=NRT&coreNodeName=core_node3&name=cdcr-cluster2_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1399
[junit4] 2> 3575434 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-cluster2&newCollection=true&collection=cdcr-cluster2&version=2&replicaType=NRT&coreNodeName=core_node4&name=cdcr-cluster2_shard2_replica_n2&action=CREATE&numShards=2&shard=shard2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin} status=0 QTime=1399
[junit4] 2> 3575438 INFO (qtp284612327-32855) [n:127.0.0.1:46660_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> 3575536 INFO (zkCallback-9911-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-cluster2/state.json] for collection [cdcr-cluster2] has occurred - updating... (live nodes size: [1])
[junit4] 2> 3575714 INFO (OverseerCollectionConfigSetProcessor-72530618166411267-127.0.0.1:46660_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 3576439 INFO (qtp284612327-32855) [n:127.0.0.1:46660_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=cdcr-cluster2&maxShardsPerNode=2&name=cdcr-cluster2&nrtReplicas=1&action=CREATE&numShards=2&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2733
[junit4] 2> 3576448 INFO (zkConnectionManagerCallback-9971-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3576450 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3576451 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33287/solr ready
[junit4] 2> 3576457 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3576457 INFO (qtp284612327-32854) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576459 INFO (qtp284612327-32858) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3576459 INFO (qtp284612327-32858) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576459 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={_stateVer_=cdcr-cluster2:4&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 3576459 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-cluster2 with checkpoint -1 @ cdcr-cluster1:shard1
[junit4] 2> 3576459 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-cluster2, shard: shard1
[junit4] 2> 3576469 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
[junit4] 2> 3576470 INFO (cdcr-bootstrap-status-9967-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-cluster2 shard: shard1 leader: http://127.0.0.1:46660/solr/cdcr-cluster2_shard1_replica_n1/
[junit4] 2> 3576471 INFO (zkCallback-9936-thread-2) [ ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-cluster1/cdcr/state/process @ cdcr-cluster1:shard2
[junit4] 2> 3576471 INFO (zkCallback-9936-thread-1) [ ] o.a.s.h.CdcrProcessStateManager The CDCR process state has changed: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-cluster1/cdcr/state/process @ cdcr-cluster1:shard1
[junit4] 2> 3576472 INFO (zkCallback-9936-thread-1) [ ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-cluster1:shard1
[junit4] 2> 3576472 INFO (zkCallback-9936-thread-2) [ ] o.a.s.h.CdcrProcessStateManager Received new CDCR process state from watcher: STARTED @ cdcr-cluster1:shard2
[junit4] 2> 3576472 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&_stateVer_=cdcr-cluster1:4&action=start&wt=javabin&version=2} status=0 QTime=27
[junit4] 2> 3576473 INFO (qtp284612327-32853) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&masterUrl=http://127.0.0.1:45952/solr/cdcr-cluster1_shard1_replica_n1/&action=BOOTSTRAP&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 3576474 INFO (zkConnectionManagerCallback-9976-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 3576476 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576476 INFO (cdcr-bootstrap-status-9967-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager CDCR bootstrap running for 1 seconds, sleeping for 2000 ms
[junit4] 2> 3576476 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 3576477 INFO (zkCallback-9936-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3576478 INFO (zkCallback-9936-thread-2) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33287/solr ready
[junit4] 2> 3576479 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1606364727766679552,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3576479 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 3576479 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3576480 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/update params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 3576482 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 3576482 INFO (qtp284612327-32853) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3576482 INFO (qtp284612327-32853) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576482 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 3576483 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 3576483 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 3576483 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 3576483 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
[junit4] 2> 3576483 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@445e3c10[cdcr-cluster2_shard1_replica_n1] main]
[junit4] 2> 3576485 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3576485 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576486 INFO (searcherExecutor-12077-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-cluster2_shard1_replica_n1] Registered new searcher Searcher@445e3c10[cdcr-cluster2_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3576486 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard1_replica_n1 c:cdcr-cluster2 s:shard1 r:core_node3) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrRequestHandler No replay needed.
[junit4] 2> 3576486 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={_stateVer_=cdcr-cluster2:4&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 3576486 INFO (zkCallback-9936-thread-2) [ ] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-cluster2 with checkpoint -1 @ cdcr-cluster1:shard2
[junit4] 2> 3576486 INFO (zkCallback-9936-thread-2) [ ] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-cluster2, shard: shard2
[junit4] 2> 3576486 INFO (zkCallback-9936-thread-2) [ ] o.a.s.h.CdcrReplicatorManager Submitting bootstrap task to executor
[junit4] 2> 3576487 INFO (cdcr-bootstrap-status-9972-thread-1) [ ] o.a.s.h.CdcrReplicatorManager Attempting to bootstrap target collection: cdcr-cluster2 shard: shard2 leader: http://127.0.0.1:46660/solr/cdcr-cluster2_shard2_replica_n2/
[junit4] 2> 3576488 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 3576488 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={qt=/cdcr&masterUrl=http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/&action=BOOTSTRAP&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576489 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3576489 INFO (cdcr-bootstrap-status-9972-thread-1) [ ] o.a.s.h.CdcrReplicatorManager CDCR bootstrap running for 1 seconds, sleeping for 2000 ms
[junit4] 2> 3576490 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1606364727778213888,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3576490 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 3576491 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3576491 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/update params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&commit_end_point=true&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 3576493 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 3576493 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 3576493 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 3576493 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 3576493 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 3576493 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
[junit4] 2> 3576494 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@61a601d2[cdcr-cluster2_shard2_replica_n2] main]
[junit4] 2> 3576495 INFO (searcherExecutor-12078-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.SolrCore [cdcr-cluster2_shard2_replica_n2] Registered new searcher Searcher@61a601d2[cdcr-cluster2_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3576495 INFO (recoveryExecutor-9908-thread-1-processing-n:127.0.0.1:46660_solr x:cdcr-cluster2_shard2_replica_n2 c:cdcr-cluster2 s:shard2 r:core_node4) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.CdcrRequestHandler No replay needed.
[junit4] 2> 3578476 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.CdcrBidirectionalTest Adding 10 docs with commit=true, numDocs=100
[junit4] 2> 3578477 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578477 INFO (cdcr-bootstrap-status-9967-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager CDCR bootstrap successful in 3 seconds
[junit4] 2> 3578482 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3578482 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578482 INFO (qtp284612327-32853) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3578482 INFO (qtp284612327-32853) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578483 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={_stateVer_=cdcr-cluster2:4&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 3578483 INFO (cdcr-bootstrap-status-9967-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-cluster2 with checkpoint -1 @ cdcr-cluster1:shard1
[junit4] 2> 3578494 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster1/terms/shard1 to Terms{values={core_node3=1}, version=1}
[junit4] 2> 3578494 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-cluster1:4&wt=javabin&version=2} status=0 QTime=15
[junit4] 2> 3578494 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={qt=/cdcr&action=BOOTSTRAP_STATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578495 INFO (cdcr-bootstrap-status-9972-thread-1) [ ] o.a.s.h.CdcrReplicatorManager CDCR bootstrap successful in 3 seconds
[junit4] 2> 3578499 INFO (qtp284612327-32855) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3578499 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.h.CdcrRequestHandler Found maxVersionFromRecent 0 maxVersionFromIndex 0
[junit4] 2> 3578499 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578499 INFO (qtp284612327-32855) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/cdcr params={action=SHARDCHECKPOINT&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 3578499 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/cdcr params={_stateVer_=cdcr-cluster2:4&action=COLLECTIONCHECKPOINT&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 3578500 INFO (cdcr-bootstrap-status-9972-thread-1) [ ] o.a.s.h.CdcrReplicatorManager Create new update log reader for target cdcr-cluster2 with checkpoint -1 @ cdcr-cluster1:shard2
[junit4] 2> 3578500 INFO (cdcr-bootstrap-status-9972-thread-1) [ ] o.a.s.h.CdcrReplicatorManager Bootstrap successful, giving the go-ahead to replicator
[junit4] 2> 3578500 INFO (cdcr-bootstrap-status-9967-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.h.CdcrReplicatorManager Bootstrap successful, giving the go-ahead to replicator
[junit4] 2> 3578503 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster1/terms/shard2 to Terms{values={core_node4=1}, version=1}
[junit4] 2> 3578503 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=cdcr-cluster1:4&wt=javabin&version=2} status=0 QTime=25
[junit4] 2> 3578506 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1606364729892143104,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3578507 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1606364729893191680,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3578507 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5aa8e3b3 commitCommandVersion:1606364729893191680
[junit4] 2> 3578511 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5c13fca commitCommandVersion:1606364729892143104
[junit4] 2> 3579389 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@614f4e7a[cdcr-cluster1_shard2_replica_n2] main]
[junit4] 2> 3579389 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3579391 INFO (searcherExecutor-12066-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard2_replica_n2 c:cdcr-cluster1 s:shard2 r:core_node4) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.SolrCore [cdcr-cluster1_shard2_replica_n2] Registered new searcher Searcher@614f4e7a[cdcr-cluster1_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C57)))}
[junit4] 2> 3579391 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&update.chain=cdcr-processor-chain&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=884
[junit4] 2> 3579423 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5476b059[cdcr-cluster1_shard1_replica_n1] main]
[junit4] 2> 3579423 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3579428 INFO (searcherExecutor-12065-thread-1-processing-n:127.0.0.1:45952_solr x:cdcr-cluster1_shard1_replica_n1 c:cdcr-cluster1 s:shard1 r:core_node3) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.SolrCore [cdcr-cluster1_shard1_replica_n1] Registered new searcher Searcher@5476b059[cdcr-cluster1_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C43)))}
[junit4] 2> 3579428 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&update.chain=cdcr-processor-chain&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:45952/solr/cdcr-cluster1_shard2_replica_n2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false} status=0 QTime=922
[junit4] 2> 3579428 INFO (qtp2135776655-32912) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=cdcr-cluster1:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2} status=0 QTime=925
[junit4] 2> 3579428 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.c.c.CdcrBidirectionalTest Adding 10 docs with commit=true, numDocs=200
[junit4] 2> 3579512 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster2/terms/shard1 to Terms{values={core_node3=1}, version=1}
[junit4] 2> 3579512 INFO (qtp284612327-32857) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard1 r:core_node3 x:cdcr-cluster2_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster2_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-cluster2:4&cdcr.update=&wt=javabin&version=2} status=0 QTime=33
[junit4] 2> 3579513 INFO (cdcr-replicator-12091-thread-1) [ ] o.a.s.h.CdcrReplicator Forwarded 43 updates to target cdcr-cluster2
[junit4] 2> 3579531 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard2 r:core_node4 x:cdcr-cluster1_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster1_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=cdcr-cluster1:4&wt=javabin&version=2} status=0 QTime=30
[junit4] 2> 3579533 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/cdcr-cluster2/terms/shard2 to Terms{values={core_node4=1}, version=1}
[junit4] 2> 3579533 INFO (qtp284612327-32856) [n:127.0.0.1:46660_solr c:cdcr-cluster2 s:shard2 r:core_node4 x:cdcr-cluster2_shard2_replica_n2] o.a.s.c.S.Request [cdcr-cluster2_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=cdcr-cluster2:4&cdcr.update=&wt=javabin&version=2} status=0 QTime=38
[junit4] 2> 3579533 INFO (cdcr-replicator-12094-thread-1) [ ] o.a.s.h.CdcrReplicator Forwarded 57 updates to target cdcr-cluster2
[junit4] 2> 3579548 INFO (qtp2135776655-32910) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.c.S.Request [cdcr-cluster1_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=cdcr-cluster1:4&wt=javabin&version=2} status=0 QTime=119
[junit4] 2> 3579549 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1606364730985807872,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3579549 INFO (qtp2135776655-32908) [n:127.0.0.1:45952_solr c:cdcr-cluster1 s:shard1 r:core_node3 x:cdcr-cluster1_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5c13fca commitCommandVersion:1606364730985807872
[junit4] 2> 3579551 INFO (qtp2135776655-32907) [n:127.0.0.1:45952_solr c:cdcr-cluster
[...truncated too long message...]
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/cdcr-cluster2/cdcr/state/process
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 3 /solr/collections/cdcr-cluster2/state.json
[junit4] 2> 2 /solr/collections/cdcr-cluster2/cdcr/state/buffer
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 5 /solr/collections
[junit4] 2>
[junit4] 2> 36116 INFO (TEST-CdcrBidirectionalTest.testBiDir-seed#[8FF7A505CA5F3397]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBiDir
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CdcrBidirectionalTest -Dtests.method=testBiDir -Dtests.seed=8FF7A505CA5F3397 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=sr-Latn-BA -Dtests.timezone=America/Argentina/La_Rioja -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 32.2s J1 | CdcrBidirectionalTest.testBiDir <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=216, name=cdcr-replicator-61-thread-1, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
[junit4] > Caused by: java.lang.AssertionError: 1606366857782099968 != 1606366857310240768
[junit4] > at __randomizedtesting.SeedInfo.seed([8FF7A505CA5F3397]:0)
[junit4] > at org.apache.solr.update.CdcrUpdateLog$CdcrLogReader.forwardSeek(CdcrUpdateLog.java:611)
[junit4] > at org.apache.solr.handler.CdcrReplicator.run(CdcrReplicator.java:125)
[junit4] > at org.apache.solr.handler.CdcrReplicatorScheduler.lambda$null$0(CdcrReplicatorScheduler.java:81)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[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)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=225, name=cdcr-replicator-64-thread-1, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
[junit4] > Caused by: java.lang.AssertionError: 1606366857315483648 != 1606366857310240768
[junit4] > at __randomizedtesting.SeedInfo.seed([8FF7A505CA5F3397]:0)
[junit4] > at org.apache.solr.update.CdcrUpdateLog$CdcrLogReader.forwardSeek(CdcrUpdateLog.java:611)
[junit4] > at org.apache.solr.handler.CdcrReplicator.run(CdcrReplicator.java:125)
[junit4] > at org.apache.solr.handler.CdcrReplicatorScheduler.lambda$null$0(CdcrReplicatorScheduler.java:81)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[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)Throwable #3: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=245, name=cdcr-replicator-61-thread-2, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
[junit4] > Caused by: java.lang.AssertionError: 1606366857782099968 != 1606366857310240768
[junit4] > at __randomizedtesting.SeedInfo.seed([8FF7A505CA5F3397]:0)
[junit4] > at org.apache.solr.update.CdcrUpdateLog$CdcrLogReader.forwardSeek(CdcrUpdateLog.java:611)
[junit4] > at org.apache.solr.handler.CdcrReplicator.run(CdcrReplicator.java:125)
[junit4] > at org.apache.solr.handler.CdcrReplicatorScheduler.lambda$null$0(CdcrReplicatorScheduler.java:81)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[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)Throwable #4: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=246, name=cdcr-replicator-64-thread-2, state=RUNNABLE, group=TGRP-CdcrBidirectionalTest]
[junit4] > Caused by: java.lang.AssertionError: 1606366857315483648 != 1606366857310240768
[junit4] > at __randomizedtesting.SeedInfo.seed([8FF7A505CA5F3397]:0)
[junit4] > at org.apache.solr.update.CdcrUpdateLog$CdcrLogReader.forwardSeek(CdcrUpdateLog.java:611)
[junit4] > at org.apache.solr.handler.CdcrReplicator.run(CdcrReplicator.java:125)
[junit4] > at org.apache.solr.handler.CdcrReplicatorScheduler.lambda$null$0(CdcrReplicatorScheduler.java:81)
[junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[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)
[junit4] 2> 36125 INFO (SUITE-CdcrBidirectionalTest-seed#[8FF7A505CA5F3397]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> Jul 18, 2018 9:53:38 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 4 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=2, maxDocsPerChunk=825, blockSize=701), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=2, blockSize=701)), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4a854080), locale=sr-Latn-BA, timezone=America/Argentina/La_Rioja
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=3,threads=1,free=51192824,total=97648640
[junit4] 2> NOTE: All tests run in this JVM: [CdcrBidirectionalTest]
[junit4] Completed [1/5 (1!)] on J1 in 35.71s, 1 test, 1 error <<< FAILURES!
[junit4]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[junit4] OK 32.7s J0 | CdcrBidirectionalTest.testBiDir
[junit4] Completed [2/5 (1!)] on J0 in 36.11s, 1 test
[junit4]
[junit4] Duplicate suite name used with XML reports: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest. This may confuse tools that process XML reports. Set 'ignoreDuplicateSuites' to true to skip this message.
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[junit4] OK 26.6s J0 | CdcrBidirectionalTest.testBiDir
[junit4] Completed [3/5 (1!)] on J0 in 26.67s, 1 test
[junit4]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[junit4] OK 27.2s J1 | CdcrBidirectionalTest.testBiDir
[junit4] Completed [4/5 (1!)] on J1 in 28.01s, 1 test
[junit4]
[junit4] Suite: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[junit4] OK 23.3s J0 | CdcrBidirectionalTest.testBiDir
[junit4] Completed [5/5 (1!)] on J0 in 24.41s, 1 test
[junit4]
[junit4]
[junit4] Tests with failures [seed: 8FF7A505CA5F3397]:
[junit4] - org.apache.solr.cloud.cdcr.CdcrBidirectionalTest.testBiDir
[junit4]
[junit4]
[junit4] JVM J0: 1.00 .. 89.11 = 88.11s
[junit4] JVM J1: 0.74 .. 65.91 = 65.17s
[junit4] Execution time total: 1 minute 29 seconds
[junit4] Tests summary: 5 suites, 5 tests, 1 error
BUILD FAILED
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/common-build.xml:1568: The following error occurred while executing this line:
/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/lucene/common-build.xml:1092: There were test failures: 5 suites, 5 tests, 1 error [seed: 8FF7A505CA5F3397]
Total time: 1 minute 32 seconds
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 1/5 failed: org.apache.solr.cloud.cdcr.CdcrBidirectionalTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=eafc9ffc6f90d267b87d35b795e89eaa7a60182a, workspace=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris
[WARNINGS] Computing warning deltas based on reference build #1976
Recording test results
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1978 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1978/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4: ClusterState says we are the leader (http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4), but locally we don't think so. Request came from null
Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from server at http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4: ClusterState says we are the leader (http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4), but locally we don't think so. Request came from null
at __randomizedtesting.SeedInfo.seed([31960EAAAEB044D1:79E37A1EA8836B44]:0)
at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:551)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1015)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:886)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:948)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:819)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:465)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4: ClusterState says we are the leader (http://127.0.0.1:59377/solr/awhollynewcollection_0_shard3_replica_n4), but locally we don't think so. Request came from null
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:528)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
... 1 more
Build Log:
[...truncated 14023 lines...]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/init-core-data-001
[junit4] 2> 2685683 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 2685683 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2685685 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2685685 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2685696 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001
[junit4] 2> 2685697 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2685697 INFO (Thread-8444) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2685697 INFO (Thread-8444) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2685699 ERROR (Thread-8444) [ ] 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> 2685797 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34407
[junit4] 2> 2685800 INFO (zkConnectionManagerCallback-8634-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2685805 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2685805 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2685805 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2685806 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2685806 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2685807 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2685807 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@152c5532{/solr,null,AVAILABLE}
[junit4] 2> 2685806 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
[junit4] 2> 2685816 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2685811 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d6894dc{HTTP/1.1,[http/1.1]}{127.0.0.1:59377}
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.e.j.s.Server Started @2687253ms
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=59377}
[junit4] 2> 2685819 ERROR (jetty-launcher-8631-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2685819 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-19T07:41:57.098Z
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@61eba538{/solr,null,AVAILABLE}
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@29eaedd1{HTTP/1.1,[http/1.1]}{127.0.0.1:36715}
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.e.j.s.Server Started @2687255ms
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36715}
[junit4] 2> 2685820 ERROR (jetty-launcher-8631-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2685820 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-19T07:41:57.099Z
[junit4] 2> 2685822 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2685822 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2685822 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2685822 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@30985505{/solr,null,AVAILABLE}
[junit4] 2> 2685823 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3450c97b{HTTP/1.1,[http/1.1]}{127.0.0.1:64770}
[junit4] 2> 2685823 INFO (jetty-launcher-8631-thread-1) [ ] o.e.j.s.Server Started @2687258ms
[junit4] 2> 2685823 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=64770}
[junit4] 2> 2685825 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6a308ed{/solr,null,AVAILABLE}
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@42dac65b{HTTP/1.1,[http/1.1]}{127.0.0.1:46905}
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.e.j.s.Server Started @2687260ms
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46905}
[junit4] 2> 2685826 ERROR (jetty-launcher-8631-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2685826 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-19T07:41:57.105Z
[junit4] 2> 2685828 ERROR (jetty-launcher-8631-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2685828 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2685828 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.0.0
[junit4] 2> 2685828 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2685828 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2685828 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-07-19T07:41:57.107Z
[junit4] 2> 2685833 INFO (zkConnectionManagerCallback-8640-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2685834 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2685836 INFO (zkConnectionManagerCallback-8638-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2685836 INFO (zkConnectionManagerCallback-8636-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2685837 INFO (zkConnectionManagerCallback-8642-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2685838 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2685838 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2685839 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 2685839 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 2685842 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 2685842 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 2685847 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2685849 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 2685850 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 2685855 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 2685855 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 2686495 INFO (jetty-launcher-8631-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34407/solr
[junit4] 2> 2686517 INFO (jetty-launcher-8631-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34407/solr
[junit4] 2> 2686519 INFO (zkConnectionManagerCallback-8650-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2686557 INFO (zkConnectionManagerCallback-8646-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2686560 INFO (zkConnectionManagerCallback-8652-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2686563 INFO (zkConnectionManagerCallback-8654-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2686948 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36715_solr
[junit4] 2> 2686950 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.c.Overseer Overseer (id=72533066581082119-127.0.0.1:36715_solr-n_0000000000) starting
[junit4] 2> 2686994 INFO (zkConnectionManagerCallback-8663-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2687005 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34407/solr ready
[junit4] 2> 2687013 INFO (OverseerStateUpdate-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:36715_solr
[junit4] 2> 2687038 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36715_solr
[junit4] 2> 2687082 INFO (zkCallback-8662-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2687083 INFO (zkCallback-8651-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2687132 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2687154 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2687154 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46905_solr
[junit4] 2> 2687155 INFO (zkCallback-8662-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2687157 INFO (zkCallback-8651-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2687158 INFO (zkCallback-8653-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2687193 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2687207 INFO (zkConnectionManagerCallback-8668-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2687210 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2687218 INFO (jetty-launcher-8631-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34407/solr
[junit4] 2> 2687226 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687310 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34407/solr ready
[junit4] 2> 2687310 INFO (zkConnectionManagerCallback-8673-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2687312 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2687322 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687322 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687325 INFO (jetty-launcher-8631-thread-4) [n:127.0.0.1:36715_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node4
[junit4] 2> 2687330 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x101b0709409000b, likely client has closed socket
[junit4] 2> 2687344 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687354 INFO (zkConnectionManagerCallback-8676-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2687369 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2687377 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687377 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687378 INFO (jetty-launcher-8631-thread-2) [n:127.0.0.1:46905_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node2
[junit4] 2> 2687383 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2687383 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64770_solr
[junit4] 2> 2687386 INFO (zkCallback-8653-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2687443 INFO (zkCallback-8651-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2687447 INFO (zkCallback-8662-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2687447 INFO (zkCallback-8667-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2687449 INFO (zkCallback-8675-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2687476 INFO (zkConnectionManagerCallback-8683-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2687478 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2687480 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34407/solr ready
[junit4] 2> 2687481 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2687536 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687573 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687573 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2687576 INFO (jetty-launcher-8631-thread-1) [n:127.0.0.1:64770_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node1
[junit4] 2> 2690444 INFO (jetty-launcher-8631-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34407/solr
[junit4] 2> 2690447 INFO (zkConnectionManagerCallback-8688-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2690451 INFO (zkConnectionManagerCallback-8690-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2690461 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2690470 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2690470 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59377_solr
[junit4] 2> 2690472 INFO (zkCallback-8675-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690472 INFO (zkCallback-8653-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690472 INFO (zkCallback-8651-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690472 INFO (zkCallback-8662-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690472 INFO (zkCallback-8667-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690472 INFO (zkCallback-8682-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690473 INFO (zkCallback-8689-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2690510 INFO (zkConnectionManagerCallback-8697-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2690512 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690513 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34407/solr ready
[junit4] 2> 2690514 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2690535 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2690546 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2690546 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2690548 INFO (jetty-launcher-8631-thread-3) [n:127.0.0.1:59377_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node3
[junit4] 2> 2690593 INFO (zkConnectionManagerCallback-8700-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2690596 INFO (zkConnectionManagerCallback-8705-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2690598 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690599 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31960EAAAEB044D1]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34407/solr ready
[junit4] 2> 2690636 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 2690637 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31960EAAAEB044D1]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690642 INFO (qtp1781814748-32929) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2690648 INFO (OverseerThreadFactory-11371-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection
[junit4] 2> 2690650 WARN (OverseerThreadFactory-11371-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 10 on collection collection 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> 2690651 ERROR (OverseerThreadFactory-11371-thread-1) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2, value of nrtReplicas is 10, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.buildReplicaPositions(CreateCollectionCmd.java:330)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:123)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:255)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 2690660 INFO (qtp1781814748-32929) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=18
[junit4] 2> 2690661 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 2690697 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
[junit4] 2> 2690698 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31960EAAAEB044D1]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690702 INFO (qtp1781814748-32898) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2690707 INFO (OverseerThreadFactory-11371-thread-2) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection oversharded
[junit4] 2> 2690707 INFO (OverseerCollectionConfigSetProcessor-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2690708 ERROR (OverseerThreadFactory-11371-thread-2) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: oversharded operation: create failed:org.apache.solr.common.SolrException: Cannot create collection oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 3, value of nrtReplicas is 2, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 6 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.buildReplicaPositions(CreateCollectionCmd.java:330)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:123)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:255)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 2690712 INFO (qtp1781814748-32898) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2} status=400 QTime=9
[junit4] 2> 2690712 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard
[junit4] 2> 2690746 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards
[junit4] 2> 2690747 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[31960EAAAEB044D1]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690751 INFO (qtp1781814748-32928) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2690757 INFO (OverseerThreadFactory-11371-thread-3) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 2690758 INFO (OverseerCollectionConfigSetProcessor-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2690758 ERROR (OverseerThreadFactory-11371-thread-3) [ ] o.a.s.c.a.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards must be > 0
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.buildReplicaPositions(CreateCollectionCmd.java:287)
[junit4] 2> at org.apache.solr.cloud.api.collections.CreateCollectionCmd.call(CreateCollectionCmd.java:123)
[junit4] 2> at org.apache.solr.cloud.api.collections.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:255)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:473)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 2690761 INFO (qtp1781814748-32928) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2} status=400 QTime=10
[junit4] 2> 2690762 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZeroNumShards
[junit4] 2> 2690791 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionsAPI-seed#[31960EAAAEB044D1]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionsAPI
[junit4] 2> 2690793 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionsAPI-seed#[31960EAAAEB044D1]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2690796 INFO (qtp1781814748-32930) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params async=104f6269-12e9-4c7a-89f6-1f0cc22e14c3&collection.configName=conf2&maxShardsPerNode=2&name=awhollynewcollection_0&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2690800 INFO (qtp1781814748-32930) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=104f6269-12e9-4c7a-89f6-1f0cc22e14c3&collection.configName=conf2&maxShardsPerNode=2&name=awhollynewcollection_0&nrtReplicas=1&action=CREATE&numShards=4&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 2690802 INFO (OverseerThreadFactory-11371-thread-4) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection awhollynewcollection_0
[junit4] 2> 2690803 INFO (OverseerCollectionConfigSetProcessor-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2690809 INFO (zkCallback-8704-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2690913 INFO (OverseerStateUpdate-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"awhollynewcollection_0",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"awhollynewcollection_0_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:64770/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2690916 INFO (OverseerStateUpdate-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"awhollynewcollection_0",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"awhollynewcollection_0_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36715/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2690919 INFO (OverseerStateUpdate-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"awhollynewcollection_0",
[junit4] 2> "shard":"shard3",
[junit4] 2> "core":"awhollynewcollection_0_shard3_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59377/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2690925 INFO (OverseerStateUpdate-72533066581082119-127.0.0.1:36715_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"awhollynewcollection_0",
[junit4] 2> "shard":"shard4",
[junit4] 2> "core":"awhollynewcollection_0_shard4_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46905/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2691029 INFO (zkCallback-8704-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2691030 WARN (watches-8702-thread-1) [ ] o.a.s.c.c.ZkStateReader Error on calling watcher
[junit4] 2> java.lang.NullPointerException: null
[junit4] 2> at java.util.TreeMap.getEntry(TreeMap.java:347) ~[?:1.8.0_172]
[junit4] 2> at java.util.TreeMap.containsKey(TreeMap.java:232) ~[?:1.8.0_172]
[junit4] 2> at java.util.TreeSet.contains(TreeSet.java:234) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.common.cloud.Replica.isActive(Replica.java:166) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.DocCollection.isFullyActive(DocCollection.java:301) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest.lambda$testCollectionsAPI$9(CollectionsAPIDistributedZkTest.java:449) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.SolrCloudTestCase.lambda$waitForState$0(SolrCloudTestCase.java:275) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.lambda$waitForState$9(ZkStateReader.java:1459) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$Notification.run(ZkStateReader.java:1642) ~[java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 2691130 INFO (qtp1781814748-32928) [n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805&coreNodeName=core_node3&name=awhollynewcollection_0_shard1_replica_n1&action=CREATE&numShards=4&shard=shard1&wt=javabin} status=0 QTime=0
[junit4] 2> 2691130 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805&coreNodeName=core_node3&name=awhollynewcollection_0_shard1_replica_n1&action=CREATE&numShards=4&shard=shard1&wt=javabin
[junit4] 2> 2691131 INFO (qtp1726290746-32903) [n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974&coreNodeName=core_node7&name=awhollynewcollection_0_shard3_replica_n4&action=CREATE&numShards=4&shard=shard3&wt=javabin} status=0 QTime=0
[junit4] 2> 2691131 INFO (qtp2097845191-32914) [n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565&coreNodeName=core_node8&name=awhollynewcollection_0_shard4_replica_n6&action=CREATE&numShards=4&shard=shard4&wt=javabin} status=0 QTime=0
[junit4] 2> 2691131 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974&coreNodeName=core_node7&name=awhollynewcollection_0_shard3_replica_n4&action=CREATE&numShards=4&shard=shard3&wt=javabin
[junit4] 2> 2691132 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565&coreNodeName=core_node8&name=awhollynewcollection_0_shard4_replica_n6&action=CREATE&numShards=4&shard=shard4&wt=javabin
[junit4] 2> 2691133 INFO (qtp1365802348-32920) [n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237&coreNodeName=core_node5&name=awhollynewcollection_0_shard2_replica_n2&action=CREATE&numShards=4&shard=shard2&wt=javabin} status=0 QTime=0
[junit4] 2> 2691134 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&collection=awhollynewcollection_0&version=2&replicaType=NRT&async=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237&coreNodeName=core_node5&name=awhollynewcollection_0_shard2_replica_n2&action=CREATE&numShards=4&shard=shard2&wt=javabin
[junit4] 2> 2691134 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2691134 INFO (qtp1781814748-32930) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805
[junit4] 2> 2691134 INFO (qtp1781814748-32930) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2691248 INFO (zkCallback-8704-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2692138 INFO (qtp1781814748-32928) [n:127.0.0.1:64770_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805
[junit4] 2> 2692138 INFO (qtp1781814748-32928) [n:127.0.0.1:64770_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2692173 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2692180 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2692188 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2692198 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2692201 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.s.IndexSchema [awhollynewcollection_0_shard4_replica_n6] Schema name=minimal
[junit4] 2> 2692202 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.s.IndexSchema [awhollynewcollection_0_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2692218 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2692218 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard1_replica_n1' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 2692219 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.awhollynewcollection_0.shard1.replica_n1' (registry 'solr.core.awhollynewcollection_0.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2692219 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.s.IndexSchema [awhollynewcollection_0_shard3_replica_n4] Schema name=minimal
[junit4] 2> 2692219 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2692219 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.c.SolrCore [[awhollynewcollection_0_shard1_replica_n1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node1/awhollynewcollection_0_shard1_replica_n1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node1/awhollynewcollection_0_shard1_replica_n1/data/]
[junit4] 2> 2692220 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.s.IndexSchema [awhollynewcollection_0_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2692221 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2692221 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard3_replica_n4' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.awhollynewcollection_0.shard3.replica_n4' (registry 'solr.core.awhollynewcollection_0.shard3.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard4_replica_n6' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.c.SolrCore [[awhollynewcollection_0_shard3_replica_n4] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node3/awhollynewcollection_0_shard3_replica_n4], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node3/awhollynewcollection_0_shard3_replica_n4/data/]
[junit4] 2> 2692222 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.awhollynewcollection_0.shard4.replica_n6' (registry 'solr.core.awhollynewcollection_0.shard4.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2692223 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2692223 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SolrCore [[awhollynewcollection_0_shard4_replica_n6] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node2/awhollynewcollection_0_shard4_replica_n6], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node2/awhollynewcollection_0_shard4_replica_n6/data/]
[junit4] 2> 2692223 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2692223 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard2_replica_n2' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 2692224 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.awhollynewcollection_0.shard2.replica_n2' (registry 'solr.core.awhollynewcollection_0.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1ea808
[junit4] 2> 2692224 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2692224 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SolrCore [[awhollynewcollection_0_shard2_replica_n2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node4/awhollynewcollection_0_shard2_replica_n2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.api.collections.CollectionsAPIDistributedZkTest_31960EAAAEB044D1-001/tempDir-001/node4/awhollynewcollection_0_shard2_replica_n2/data/]
[junit4] 2> 2692334 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2692334 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2692336 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2692336 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2692337 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f677d48[awhollynewcollection_0_shard2_replica_n2] main]
[junit4] 2> 2692338 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 2692339 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 2692339 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2692339 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606403881558867968
[junit4] 2> 2692340 INFO (searcherExecutor-11397-thread-1-processing-x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 r:core_node5 CREATE n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SolrCore [awhollynewcollection_0_shard2_replica_n2] Registered new searcher Searcher@3f677d48[awhollynewcollection_0_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2692347 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/awhollynewcollection_0/terms/shard2 to Terms{values={core_node5=0}, version=0}
[junit4] 2> 2692353 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2692353 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2692353 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36715/solr/awhollynewcollection_0_shard2_replica_n2/
[junit4] 2> 2692353 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2692354 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.SyncStrategy http://127.0.0.1:36715/solr/awhollynewcollection_0_shard2_replica_n2/ has no replicas
[junit4] 2> 2692354 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2692360 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36715/solr/awhollynewcollection_0_shard2_replica_n2/ shard2
[junit4] 2> 2692445 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2692445 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2692450 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2692450 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2692466 INFO (zkCallback-8704-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2692469 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@980d81e[awhollynewcollection_0_shard4_replica_n6] main]
[junit4] 2> 2692472 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 2692473 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 2692476 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2692476 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606403881702522880
[junit4] 2> 2692491 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.ZkShardTerms Successful update of terms at /collections/awhollynewcollection_0/terms/shard4 to Terms{values={core_node8=0}, version=0}
[junit4] 2> 2692498 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2692498 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2692499 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2692500 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2692501 INFO (searcherExecutor-11396-thread-1-processing-x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 r:core_node8 CREATE n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SolrCore [awhollynewcollection_0_shard4_replica_n6] Registered new searcher Searcher@980d81e[awhollynewcollection_0_shard4_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2692501 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74ccd2f7[awhollynewcollection_0_shard1_replica_n1] main]
[junit4] 2> 2692501 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2692502 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2692502 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46905/solr/awhollynewcollection_0_shard4_replica_n6/
[junit4] 2> 2692503 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2692503 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 2692504 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 2692504 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2692504 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.SyncStrategy http://127.0.0.1:46905/solr/awhollynewcollection_0_shard4_replica_n6/ has no replicas
[junit4] 2> 2692505 INFO (parallelCoreAdminExecutor-11383-thread-1-processing-n:127.0.0.1:64770_solr x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 CREATE) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1606403881732931584
[junit4] 2> 2692505 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2692515 INFO (parallelCoreAdminExecutor-11373-thread-1-processing-n:127.0.0.1:36715_solr x:awhollynewcollection_0_shard2_replica_n2 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140460566237 CREATE) [n:127.0.0.1:36715_solr c:awhollynewcollection_0 s:shard2 r:core_node5 x:awhollynewcollection_0_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2692515 INFO (searcherExecutor-11394-thread-1-processing-x:awhollynewcollection_0_shard1_replica_n1 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140457438805 r:core_node3 CREATE n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1) [n:127.0.0.1:64770_solr c:awhollynewcollection_0 s:shard1 r:core_node3 x:awhollynewcollection_0_shard1_replica_n1] o.a.s.c.SolrCore [awhollynewcollection_0_shard1_replica_n1] Registered new searcher Searcher@74ccd2f7[awhollynewcollection_0_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2692517 INFO (parallelCoreAdminExecutor-11372-thread-1-processing-n:127.0.0.1:46905_solr x:awhollynewcollection_0_shard4_replica_n6 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140469567565 CREATE) [n:127.0.0.1:46905_solr c:awhollynewcollection_0 s:shard4 r:core_node8 x:awhollynewcollection_0_shard4_replica_n6] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46905/solr/awhollynewcollection_0_shard4_replica_n6/ shard4
[junit4] 2> 2692519 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104f6269-12e9-4c7a-89f6-1f0cc22e14c37255140463658974 CREATE) [n:127.0.0.1:59377_solr c:awhollynewcollection_0 s:shard3 r:core_node7 x:awhollynewcollection_0_shard3_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2692519 INFO (parallelCoreAdminExecutor-11390-thread-1-processing-n:127.0.0.1:59377_solr x:awhollynewcollection_0_shard3_replica_n4 104
[...truncated too long message...]
ollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes
[junit4] Completed [3/5] on J1 in 94.23s, 19 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[junit4] OK 0.07s J0 | CollectionsAPIDistributedZkTest.testTooManyReplicas
[junit4] OK 0.07s J0 | CollectionsAPIDistributedZkTest.testMaxNodesPerShard
[junit4] OK 0.06s J0 | CollectionsAPIDistributedZkTest.testZeroNumShards
[junit4] OK 14.6s J0 | CollectionsAPIDistributedZkTest.testCollectionsAPI
[junit4] OK 5.72s J0 | CollectionsAPIDistributedZkTest.testCollectionReload
[junit4] OK 2.98s J0 | CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode
[junit4] OK 3.54s J0 | CollectionsAPIDistributedZkTest.testCreationAndDeletion
[junit4] OK 0.07s J0 | CollectionsAPIDistributedZkTest.testBadActionNames
[junit4] OK 2.91s J0 | CollectionsAPIDistributedZkTest.testSpecificConfigsets
[junit4] OK 0.91s J0 | CollectionsAPIDistributedZkTest.testMissingRequiredParameters
[junit4] OK 5.13s J0 | CollectionsAPIDistributedZkTest.addReplicaTest
[junit4] OK 4.07s J0 | CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk
[junit4] OK 1.82s J0 | CollectionsAPIDistributedZkTest.testNoConfigSetExist
[junit4] OK 0.07s J0 | CollectionsAPIDistributedZkTest.testMissingNumShards
[junit4] OK 0.28s J0 | CollectionsAPIDistributedZkTest.testCreateNodeSet
[junit4] OK 4.60s J0 | CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection
[junit4] OK 34.7s J0 | CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore
[junit4] OK 5.73s J0 | CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection
[junit4] OK 4.62s J0 | CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes
[junit4] Completed [4/5] on J0 in 95.17s, 19 tests
[junit4]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[junit4] OK 0.07s J1 | CollectionsAPIDistributedZkTest.testTooManyReplicas
[junit4] OK 0.09s J1 | CollectionsAPIDistributedZkTest.testMaxNodesPerShard
[junit4] OK 0.07s J1 | CollectionsAPIDistributedZkTest.testZeroNumShards
[junit4] OK 5.58s J1 | CollectionsAPIDistributedZkTest.testCollectionsAPI
[junit4] OK 5.45s J1 | CollectionsAPIDistributedZkTest.testCollectionReload
[junit4] OK 3.04s J1 | CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode
[junit4] OK 3.56s J1 | CollectionsAPIDistributedZkTest.testCreationAndDeletion
[junit4] OK 0.07s J1 | CollectionsAPIDistributedZkTest.testBadActionNames
[junit4] OK 2.80s J1 | CollectionsAPIDistributedZkTest.testSpecificConfigsets
[junit4] OK 0.81s J1 | CollectionsAPIDistributedZkTest.testMissingRequiredParameters
[junit4] OK 4.82s J1 | CollectionsAPIDistributedZkTest.addReplicaTest
[junit4] OK 3.91s J1 | CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk
[junit4] OK 1.83s J1 | CollectionsAPIDistributedZkTest.testNoConfigSetExist
[junit4] OK 0.07s J1 | CollectionsAPIDistributedZkTest.testMissingNumShards
[junit4] OK 0.29s J1 | CollectionsAPIDistributedZkTest.testCreateNodeSet
[junit4] OK 4.36s J1 | CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection
[junit4] OK 34.7s J1 | CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore
[junit4] OK 5.76s J1 | CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection
[junit4] OK 4.47s J1 | CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes
[junit4] Completed [5/5] on J1 in 84.89s, 19 tests
[junit4]
[junit4] JVM J0: 0.67 .. 194.87 = 194.20s
[junit4] JVM J1: 0.68 .. 273.84 = 273.15s
[junit4] Execution time total: 4 minutes 33 seconds
[junit4] Tests summary: 5 suites, 95 tests
[junit4] Could not remove temporary path: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J0/temp])
[junit4] Could not remove temporary path: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp])
[echo] 5 slowest tests:
[junit4:tophints] 220.63s | org.apache.solr.update.TestInPlaceUpdatesDistrib
[junit4:tophints] 116.98s | org.apache.solr.update.SoftAutoCommitTest
[junit4:tophints] 115.36s | org.apache.solr.cloud.MoveReplicaHDFSTest
[junit4:tophints] 113.11s | org.apache.solr.cloud.ZkFailoverTest
[junit4:tophints] 109.33s | org.apache.solr.cloud.TestTlogReplica
-check-totals:
test-nocompile:
BUILD SUCCESSFUL
Total time: 4 minutes 36 seconds
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.api.collections.CollectionsAPIDistributedZkTest
[repro] Exiting with code 0
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2843)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2722)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2703)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3082)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to Solaris VBOX
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1089)
at hudson.FilePath.act(FilePath.java:1078)
at hudson.FilePath.validateAntFileMask(FilePath.java:2701)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1840)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3084)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1091)
at hudson.FilePath.act(FilePath.java:1078)
at hudson.FilePath.validateAntFileMask(FilePath.java:2701)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1840)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/*_pid*.log". Configuration error?
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=d443ed088d2d6f6d6fd0c8965e27bde660ad440f, workspace=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris
[WARNINGS] Computing warning deltas based on reference build #1977
Recording test results
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/export/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2