You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/11/17 10:03:11 UTC
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_144) - Build #
20933 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/20933/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.LeaderElectionContextKeyTest
Error Message:
Error from server at https://127.0.0.1:44047/solr: Timed out waiting to see all replicas: [testCollection1_shard2_replica_n43] in cluster state. Last state: DocCollection(testCollection1//collections/testCollection1/state.json/2)={ "pullReplicas":"0", "replicationFactor":"1", "shards":{ "shard1":{ "range":"80000000-ffffffff", "state":"active", "replicas":{"core_node42":{ "core":"testCollection1_shard1_replica_n41", "base_url":"https://127.0.0.1:44047/solr", "node_name":"127.0.0.1:44047_solr", "state":"down", "type":"NRT", "leader":"true"}}}, "shard2":{ "range":"0-7fffffff", "state":"active", "replicas":{}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"}
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:44047/solr: Timed out waiting to see all replicas: [testCollection1_shard2_replica_n43] in cluster state. Last state: DocCollection(testCollection1//collections/testCollection1/state.json/2)={
"pullReplicas":"0",
"replicationFactor":"1",
"shards":{
"shard1":{
"range":"80000000-ffffffff",
"state":"active",
"replicas":{"core_node42":{
"core":"testCollection1_shard1_replica_n41",
"base_url":"https://127.0.0.1:44047/solr",
"node_name":"127.0.0.1:44047_solr",
"state":"down",
"type":"NRT",
"leader":"true"}}},
"shard2":{
"range":"0-7fffffff",
"state":"active",
"replicas":{}}},
"router":{"name":"compositeId"},
"maxShardsPerNode":"100",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0"}
at __randomizedtesting.SeedInfo.seed([D755479BCC63C346]:0)
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.sendRequest(CloudSolrClient.java:1104)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.cloud.LeaderElectionContextKeyTest.setupCluster(LeaderElectionContextKeyTest.java:63)
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$6.evaluate(RandomizedRunner.java:874)
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)
FAILED: junit.framework.TestSuite.org.apache.solr.schema.ManagedSchemaRoundRobinCloudTest
Error Message:
Error from server at https://127.0.0.1:36115/solr: create the collection time out:180s
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:36115/solr: create the collection time out:180s
at __randomizedtesting.SeedInfo.seed([D755479BCC63C346]:0)
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.sendRequest(CloudSolrClient.java:1104)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.schema.ManagedSchemaRoundRobinCloudTest.setupCluster(ManagedSchemaRoundRobinCloudTest.java:50)
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$6.evaluate(RandomizedRunner.java:874)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11646 lines...]
[junit4] Suite: org.apache.solr.cloud.LeaderElectionContextKeyTest
[junit4] 2> 54296 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderElectionContextKeyTest_D755479BCC63C346-001/init-core-data-001
[junit4] 2> 54296 WARN (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 54296 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 54297 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 54298 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderElectionContextKeyTest_D755479BCC63C346-001/tempDir-001
[junit4] 2> 54298 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 54298 INFO (Thread-121) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 54298 INFO (Thread-121) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 54302 ERROR (Thread-121) [ ] 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> 54398 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:42563
[junit4] 2> 54406 INFO (jetty-launcher-97-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 54407 INFO (jetty-launcher-97-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@63cc2b84{/solr,null,AVAILABLE}
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@e2cf1ff{SSL,[ssl, http/1.1]}{127.0.0.1:44047}
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.e.j.s.Server Started @56250ms
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44047}
[junit4] 2> 54409 ERROR (jetty-launcher-97-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 54409 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-17T08:53:07.439Z
[junit4] 2> 54411 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 54422 INFO (jetty-launcher-97-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:42563/solr
[junit4] 2> 54465 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 54465 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44047_solr
[junit4] 2> 54465 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.c.Overseer Overseer (id=99018918286393347-127.0.0.1:44047_solr-n_0000000000) starting
[junit4] 2> 54469 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44047_solr
[junit4] 2> 54470 INFO (OverseerStateUpdate-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 54515 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44047.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6eaa5845
[junit4] 2> 54519 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44047.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6eaa5845
[junit4] 2> 54520 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44047.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6eaa5845
[junit4] 2> 54520 INFO (jetty-launcher-97-thread-1) [n:127.0.0.1:44047_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderElectionContextKeyTest_D755479BCC63C346-001/tempDir-001/node1/.
[junit4] 2> 54534 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 54535 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:42563/solr ready
[junit4] 2> 54554 INFO (qtp490074792-610) [n:127.0.0.1:44047_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=config&maxShardsPerNode=100&name=testCollection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 54555 INFO (OverseerThreadFactory-283-thread-1-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.CreateCollectionCmd Create collection testCollection1
[junit4] 2> 54556 WARN (OverseerThreadFactory-283-thread-1-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (testCollection1) without cores.
[junit4] 2> 54659 INFO (qtp490074792-610) [n:127.0.0.1:44047_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> 54659 INFO (qtp490074792-610) [n:127.0.0.1:44047_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=config&maxShardsPerNode=100&name=testCollection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&wt=javabin&version=2} status=0 QTime=104
[junit4] 2> 54661 INFO (qtp490074792-604) [n:127.0.0.1:44047_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params action=ADDREPLICA&collection=testCollection1&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 54662 INFO (OverseerCollectionConfigSetProcessor-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 54664 INFO (OverseerThreadFactory-283-thread-2-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:44047_solr for creating new replica
[junit4] 2> 54665 INFO (OverseerStateUpdate-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"testCollection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testCollection1_shard1_replica_n41",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:44047/solr",
[junit4] 2> "node_name":"127.0.0.1:44047_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 54873 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node42&collection.configName=config&name=testCollection1_shard1_replica_n41&action=CREATE&collection=testCollection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 54874 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 54887 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 54895 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.s.IndexSchema [testCollection1_shard1_replica_n41] Schema name=minimal
[junit4] 2> 54898 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 54898 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.CoreContainer Creating SolrCore 'testCollection1_shard1_replica_n41' using configuration from collection testCollection1, trusted=true
[junit4] 2> 54900 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44047.solr.core.testCollection1.shard1.replica_n41' (registry 'solr.core.testCollection1.shard1.replica_n41') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6eaa5845
[junit4] 2> 54900 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 54900 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SolrCore [[testCollection1_shard1_replica_n41] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderElectionContextKeyTest_D755479BCC63C346-001/tempDir-001/node1/testCollection1_shard1_replica_n41], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.LeaderElectionContextKeyTest_D755479BCC63C346-001/tempDir-001/node1/./testCollection1_shard1_replica_n41/data/]
[junit4] 2> 54944 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 54944 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 54945 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 54945 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 54947 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f1b5fe0[testCollection1_shard1_replica_n41] main]
[junit4] 2> 54948 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
[junit4] 2> 54948 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
[junit4] 2> 54949 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 54949 INFO (searcherExecutor-286-thread-1-processing-n:127.0.0.1:44047_solr x:testCollection1_shard1_replica_n41 s:shard1 c:testCollection1 r:core_node42) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SolrCore [testCollection1_shard1_replica_n41] Registered new searcher Searcher@5f1b5fe0[testCollection1_shard1_replica_n41] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 54949 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584302693263867904
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:44047/solr/testCollection1_shard1_replica_n41/
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SyncStrategy https://127.0.0.1:44047/solr/testCollection1_shard1_replica_n41/ has no replicas
[junit4] 2> 54953 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 54954 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:44047/solr/testCollection1_shard1_replica_n41/ shard1
[junit4] 2> 55055 INFO (zkCallback-104-thread-1-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCollection1/state.json] for collection [testCollection1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 55056 INFO (zkCallback-104-thread-2-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCollection1/state.json] for collection [testCollection1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 55105 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 55113 INFO (qtp490074792-605) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node42&collection.configName=config&name=testCollection1_shard1_replica_n41&action=CREATE&collection=testCollection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=239
[junit4] 2> 55115 INFO (qtp490074792-604) [n:127.0.0.1:44047_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=ADDREPLICA&collection=testCollection1&shard=shard1&type=NRT&wt=javabin&version=2} status=0 QTime=453
[junit4] 2> 55116 INFO (qtp490074792-608) [n:127.0.0.1:44047_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params action=ADDREPLICA&collection=testCollection1&shard=shard2&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 55119 INFO (OverseerCollectionConfigSetProcessor-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 55120 INFO (OverseerThreadFactory-283-thread-3-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:44047_solr for creating new replica
[junit4] 2> 85173 ERROR (OverseerThreadFactory-283-thread-3-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: testCollection1 operation: addreplica failed:org.apache.solr.common.SolrException: Timed out waiting to see all replicas: [testCollection1_shard2_replica_n43] in cluster state. Last state: DocCollection(testCollection1//collections/testCollection1/state.json/2)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node42":{
[junit4] 2> "core":"testCollection1_shard1_replica_n41",
[junit4] 2> "base_url":"https://127.0.0.1:44047/solr",
[junit4] 2> "node_name":"127.0.0.1:44047_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"100",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.waitToSeeReplicasInState(OverseerCollectionMessageHandler.java:703)
[junit4] 2> at org.apache.solr.cloud.AddReplicaCmd.addReplica(AddReplicaCmd.java:173)
[junit4] 2> at org.apache.solr.cloud.AddReplicaCmd.call(AddReplicaCmd.java:72)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:231)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 85189 INFO (qtp490074792-608) [n:127.0.0.1:44047_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=ADDREPLICA&collection=testCollection1&shard=shard2&type=NRT&wt=javabin&version=2} status=500 QTime=30073
[junit4] 2> 85190 ERROR (qtp490074792-608) [n:127.0.0.1:44047_solr ] o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: Timed out waiting to see all replicas: [testCollection1_shard2_replica_n43] in cluster state. Last state: DocCollection(testCollection1//collections/testCollection1/state.json/2)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "shards":{
[junit4] 2> "shard1":{
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node42":{
[junit4] 2> "core":"testCollection1_shard1_replica_n41",
[junit4] 2> "base_url":"https://127.0.0.1:44047/solr",
[junit4] 2> "node_name":"127.0.0.1:44047_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}},
[junit4] 2> "shard2":{
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"100",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleResponse(CollectionsHandler.java:307)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:244)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:222)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:735)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:716)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:497)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:493)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 85206 INFO (jetty-closer-98-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@e2cf1ff{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 85206 INFO (jetty-closer-98-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=906505105
[junit4] 2> 85209 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 85209 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@bf34b3d: rootName = solr_44047, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@11d72437
[junit4] 2> 85214 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 85214 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@453c2ee1: rootName = solr_44047, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@699b23c
[junit4] 2> 85219 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 85219 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3c148287: rootName = solr_44047, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2a63637
[junit4] 2> 85236 INFO (jetty-closer-98-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:44047_solr
[junit4] 2> 85237 INFO (zkCallback-104-thread-3-processing-n:127.0.0.1:44047_solr) [n:127.0.0.1:44047_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 85237 INFO (jetty-closer-98-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 85243 INFO (coreCloseExecutor-291-thread-1) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.c.SolrCore [testCollection1_shard1_replica_n41] CLOSING SolrCore org.apache.solr.core.SolrCore@4c54c331
[junit4] 2> 85243 INFO (coreCloseExecutor-291-thread-1) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testCollection1.shard1.replica_n41, tag=1280623409
[junit4] 2> 85243 INFO (coreCloseExecutor-291-thread-1) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@26b9eb45: rootName = solr_44047, domain = solr.core.testCollection1.shard1.replica_n41, service url = null, agent id = null] for registry solr.core.testCollection1.shard1.replica_n41 / com.codahale.metrics.MetricRegistry@74567829
[junit4] 2> 85251 INFO (coreCloseExecutor-291-thread-1) [n:127.0.0.1:44047_solr c:testCollection1 s:shard1 r:core_node42 x:testCollection1_shard1_replica_n41] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testCollection1.shard1.leader, tag=1280623409
[junit4] 2> 85269 INFO (jetty-closer-98-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99018918286393347-127.0.0.1:44047_solr-n_0000000000) closing
[junit4] 2> 85269 INFO (OverseerStateUpdate-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44047_solr
[junit4] 2> 85273 WARN (OverseerAutoScalingTriggerThread-99018918286393347-127.0.0.1:44047_solr-n_0000000000) [n:127.0.0.1:44047_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 85276 INFO (jetty-closer-98-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@63cc2b84{/solr,null,UNAVAILABLE}
[junit4] 2> 85277 ERROR (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 85277 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42563 42563
[junit4] 2> 91064 INFO (Thread-121) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42563 42563
[junit4] 2> 91064 WARN (Thread-121) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/collections/testCollection1/state.json
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> 91064 INFO (SUITE-LeaderElectionContextKeyTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1503, maxMBSortInHeap=7.412688914133337, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@61dee7de), locale=ga, timezone=America/Tortola
[junit4] 2> NOTE: Linux 4.10.0-37-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=178095032,total=472907776
[junit4] 2> NOTE: All tests run in this JVM: [URLClassifyProcessorTest, TestSubQueryTransformerCrossCore, SolrInfoBeanTest, V2ApiIntegrationTest, TestDistribIDF, TestMinMaxOnMultiValuedField, TestHighlightDedupGrouping, TestNRTOpen, TestCollationFieldDocValues, LeaderElectionContextKeyTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=LeaderElectionContextKeyTest -Dtests.seed=D755479BCC63C346 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ga -Dtests.timezone=America/Tortola -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | LeaderElectionContextKeyTest (suite) <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:44047/solr: Timed out waiting to see all replicas: [testCollection1_shard2_replica_n43] in cluster state. Last state: DocCollection(testCollection1//collections/testCollection1/state.json/2)={
[junit4] > "pullReplicas":"0",
[junit4] > "replicationFactor":"1",
[junit4] > "shards":{
[junit4] > "shard1":{
[junit4] > "range":"80000000-ffffffff",
[junit4] > "state":"active",
[junit4] > "replicas":{"core_node42":{
[junit4] > "core":"testCollection1_shard1_replica_n41",
[junit4] > "base_url":"https://127.0.0.1:44047/solr",
[junit4] > "node_name":"127.0.0.1:44047_solr",
[junit4] > "state":"down",
[junit4] > "type":"NRT",
[junit4] > "leader":"true"}}},
[junit4] > "shard2":{
[junit4] > "range":"0-7fffffff",
[junit4] > "state":"active",
[junit4] > "replicas":{}}},
[junit4] > "router":{"name":"compositeId"},
[junit4] > "maxShardsPerNode":"100",
[junit4] > "autoAddReplicas":"false",
[junit4] > "nrtReplicas":"1",
[junit4] > "tlogReplicas":"0"}
[junit4] > at __randomizedtesting.SeedInfo.seed([D755479BCC63C346]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1104)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
[junit4] > at org.apache.solr.cloud.LeaderElectionContextKeyTest.setupCluster(LeaderElectionContextKeyTest.java:63)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] Completed [29/750 (1!)] on J0 in 36.78s, 0 tests, 1 error <<< FAILURES!
[...truncated 2430 lines...]
[junit4] Suite: org.apache.solr.schema.ManagedSchemaRoundRobinCloudTest
[junit4] 2> 3149488 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/init-core-data-001
[junit4] 2> 3149488 WARN (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=25 numCloses=25
[junit4] 2> 3149488 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 3149489 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 3149490 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001
[junit4] 2> 3149490 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 3149491 INFO (Thread-8664) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 3149491 INFO (Thread-8664) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 3149516 ERROR (Thread-8664) [ ] 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> 3149591 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33369
[junit4] 2> 3149604 INFO (jetty-launcher-3534-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3149604 INFO (jetty-launcher-3534-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 3149625 INFO (jetty-launcher-3534-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@739e7f79{/solr,null,AVAILABLE}
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7b69d5a7{SSL,[ssl, http/1.1]}{127.0.0.1:36115}
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.e.j.s.Server Started @3151311ms
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36115}
[junit4] 2> 3149626 ERROR (jetty-launcher-3534-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3149626 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-17T09:44:42.507Z
[junit4] 2> 3149656 INFO (jetty-launcher-3534-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@431ae00b{/solr,null,AVAILABLE}
[junit4] 2> 3149656 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3149657 INFO (jetty-launcher-3534-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@ad94f7f{SSL,[ssl, http/1.1]}{127.0.0.1:39709}
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.e.j.s.Server Started @3151344ms
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39709}
[junit4] 2> 3149659 ERROR (jetty-launcher-3534-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 3149659 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-17T09:44:42.540Z
[junit4] 2> 3149678 INFO (jetty-launcher-3534-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33369/solr
[junit4] 2> 3149681 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 3149689 INFO (jetty-launcher-3534-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33369/solr
[junit4] 2> 3149713 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3149713 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39709_solr
[junit4] 2> 3149714 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.c.Overseer Overseer (id=99019121123983366-127.0.0.1:39709_solr-n_0000000000) starting
[junit4] 2> 3149729 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39709_solr
[junit4] 2> 3149753 INFO (zkCallback-3546-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3149769 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 3149770 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 3149772 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36115_solr
[junit4] 2> 3149772 INFO (zkCallback-3546-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3149784 INFO (zkCallback-3545-thread-1-processing-n:127.0.0.1:36115_solr) [n:127.0.0.1:36115_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 3149850 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36115.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149850 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39709.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149857 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36115.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149857 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39709.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149858 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36115.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149858 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39709.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3149859 INFO (jetty-launcher-3534-thread-2) [n:127.0.0.1:36115_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node2/.
[junit4] 2> 3149859 INFO (jetty-launcher-3534-thread-1) [n:127.0.0.1:39709_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node1/.
[junit4] 2> 3149909 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 3149909 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33369/solr ready
[junit4] 2> 3149938 INFO (qtp1168839042-27659) [n:127.0.0.1:36115_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cloud-managed&maxShardsPerNode=1&name=managed_coll&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 3149948 INFO (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.CreateCollectionCmd Create collection managed_coll
[junit4] 2> 3150054 INFO (OverseerStateUpdate-99019121123983366-127.0.0.1:39709_solr-n_0000000000) [n:127.0.0.1:39709_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"managed_coll",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"managed_coll_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39709/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3150056 INFO (OverseerStateUpdate-99019121123983366-127.0.0.1:39709_solr-n_0000000000) [n:127.0.0.1:39709_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"managed_coll",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"managed_coll_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:36115/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 3150264 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=cloud-managed&newCollection=true&name=managed_coll_shard2_replica_n2&action=CREATE&numShards=2&collection=managed_coll&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 3150264 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3150287 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=cloud-managed&newCollection=true&name=managed_coll_shard1_replica_n1&action=CREATE&numShards=2&collection=managed_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 3150288 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 3150390 INFO (zkCallback-3545-thread-1-processing-n:127.0.0.1:36115_solr) [n:127.0.0.1:36115_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/managed_coll/state.json] for collection [managed_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 3150390 INFO (zkCallback-3546-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/managed_coll/state.json] for collection [managed_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 3150390 INFO (zkCallback-3545-thread-2-processing-n:127.0.0.1:36115_solr) [n:127.0.0.1:36115_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/managed_coll/state.json] for collection [managed_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 3150390 INFO (zkCallback-3546-thread-2-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/managed_coll/state.json] for collection [managed_coll] has occurred - updating... (live nodes size: [2])
[junit4] 2> 3151273 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3151279 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.s.IndexSchema [managed_coll_shard2_replica_n2] Schema name=minimal
[junit4] 2> 3151292 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3151292 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'managed_coll_shard2_replica_n2' using configuration from collection managed_coll, trusted=true
[junit4] 2> 3151292 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36115.solr.core.managed_coll.shard2.replica_n2' (registry 'solr.core.managed_coll.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3151293 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3151293 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SolrCore [[managed_coll_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node2/managed_coll_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node2/./managed_coll_shard2_replica_n2/data/]
[junit4] 2> 3151295 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 3151300 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.s.IndexSchema [managed_coll_shard1_replica_n1] Schema name=minimal
[junit4] 2> 3151301 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 3151301 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'managed_coll_shard1_replica_n1' using configuration from collection managed_coll, trusted=true
[junit4] 2> 3151302 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39709.solr.core.managed_coll.shard1.replica_n1' (registry 'solr.core.managed_coll.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@494670ca
[junit4] 2> 3151302 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 3151302 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SolrCore [[managed_coll_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node1/managed_coll_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.schema.ManagedSchemaRoundRobinCloudTest_D755479BCC63C346-001/tempDir-001/node1/./managed_coll_shard1_replica_n1/data/]
[junit4] 2> 3151334 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 3151335 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3151336 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3151336 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3151337 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 3151337 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 3151337 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@c8bb618[managed_coll_shard1_replica_n1] main]
[junit4] 2> 3151338 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 3151338 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 3151339 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cloud-managed
[junit4] 2> 3151339 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cloud-managed
[junit4] 2> 3151339 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cloud-managed/managed-schema
[junit4] 2> 3151340 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3151340 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@333ba168[managed_coll_shard2_replica_n2] main]
[junit4] 2> 3151341 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3151342 INFO (searcherExecutor-9740-thread-1-processing-n:127.0.0.1:39709_solr x:managed_coll_shard1_replica_n1 s:shard1 c:managed_coll r:core_node3) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SolrCore [managed_coll_shard1_replica_n1] Registered new searcher Searcher@c8bb618[managed_coll_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3151342 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584305939911016448
[junit4] 2> 3151343 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cloud-managed
[junit4] 2> 3151343 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cloud-managed
[junit4] 2> 3151343 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/cloud-managed/managed-schema
[junit4] 2> 3151344 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 3151345 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 3151345 INFO (searcherExecutor-9739-thread-1-processing-n:127.0.0.1:36115_solr x:managed_coll_shard2_replica_n2 s:shard2 c:managed_coll r:core_node4) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SolrCore [managed_coll_shard2_replica_n2] Registered new searcher Searcher@333ba168[managed_coll_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3151346 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584305939915210752
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:39709/solr/managed_coll_shard1_replica_n1/
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:39709/solr/managed_coll_shard1_replica_n1/ has no replicas
[junit4] 2> 3151347 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3151349 INFO (qtp177441110-27658) [n:127.0.0.1:39709_solr c:managed_coll s:shard1 r:core_node3 x:managed_coll_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:39709/solr/managed_coll_shard1_replica_n1/ shard1
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:36115/solr/managed_coll_shard2_replica_n2/
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:36115/solr/managed_coll_shard2_replica_n2/ has no replicas
[junit4] 2> 3151350 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 3151352 INFO (qtp1168839042-27660) [n:127.0.0.1:36115_solr c:managed_coll s:shard2 r:core_node4 x:managed_coll_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:36115/solr/managed_coll_shard2_replica_n2/ shard2
[junit4] 2> 3329940 ERROR (qtp1168839042-27659) [n:127.0.0.1:36115_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: create the collection time out:180s
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleResponse(CollectionsHandler.java:312)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:244)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:222)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:735)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:716)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:497)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:493)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 3329941 INFO (qtp1168839042-27659) [n:127.0.0.1:36115_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cloud-managed&maxShardsPerNode=1&name=managed_coll&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=500 QTime=180002
[junit4] 2> 3329941 ERROR (qtp1168839042-27659) [n:127.0.0.1:36115_solr ] o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: create the collection time out:180s
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleResponse(CollectionsHandler.java:312)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:244)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:222)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:735)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:716)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:497)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:493)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 3329944 ERROR (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:39709/solr
[junit4] 2> org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:39709/solr
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:657)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
[junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:172)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Caused by: org.apache.http.NoHttpResponseException: 127.0.0.1:39709 failed to respond
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:141)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
[junit4] 2> at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
[junit4] 2> at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
[junit4] 2> at org.apache.solr.util.stats.InstrumentedHttpRequestExecutor.execute(InstrumentedHttpRequestExecutor.java:118)
[junit4] 2> at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
[junit4] 2> at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
[junit4] 2> at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
[junit4] 2> at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
[junit4] 2> at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
[junit4] 2> ... 12 more
[junit4] 2> 3329951 ERROR (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:36115/solr
[junit4] 2> org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:36115/solr
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:657)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
[junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:172)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Caused by: org.apache.http.NoHttpResponseException: 127.0.0.1:36115 failed to respond
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:141)
[junit4] 2> at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
[junit4] 2> at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
[junit4] 2> at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
[junit4] 2> at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
[junit4] 2> at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
[junit4] 2> at org.apache.solr.util.stats.InstrumentedHttpRequestExecutor.execute(InstrumentedHttpRequestExecutor.java:118)
[junit4] 2> at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
[junit4] 2> at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
[junit4] 2> at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
[junit4] 2> at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
[junit4] 2> at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
[junit4] 2> at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
[junit4] 2> ... 12 more
[junit4] 2> 3329950 INFO (jetty-closer-3535-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@ad94f7f{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 3329950 INFO (jetty-closer-3535-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7b69d5a7{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 3329960 INFO (jetty-closer-3535-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=149461547
[junit4] 2> 3329957 ERROR (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerCollectionMessageHandler Cleaning up collection [managed_coll].
[junit4] 2> 3329964 INFO (jetty-closer-3535-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 3329964 INFO (jetty-closer-3535-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@42016441: rootName = solr_39709, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3e41f642
[junit4] 2> 3329964 INFO (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 3329965 INFO (jetty-closer-3535-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1560708402
[junit4] 2> 3329966 INFO (jetty-closer-3535-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 3329966 INFO (jetty-closer-3535-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@b58564f: rootName = solr_36115, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@482d36a5
[junit4] 2> 3329968 ERROR (OverseerThreadFactory-9734-thread-1-processing-n:127.0.0.1:39709_solr) [n:127.0.0.1:39709_solr ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:39709/solr
[junit4] 2> org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:39709/solr
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:650)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
[junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardH
[...truncated too long message...]
ull path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=cloud-managed&newCollection=true&name=managed_coll_shard1_replica_n1&action=CREATE&numShards=2&collection=managed_coll&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=209839
[junit4] 2> 3360127 ERROR (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 3360131 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33369 33369
[junit4] 2> 3365245 INFO (Thread-8664) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33369 33369
[junit4] 2> 3365249 WARN (Thread-8664) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 2 /solr/configs/cloud-managed
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/configs/cloud-managed/managed-schema
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/collections/managed_coll/state.json
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/collections
[junit4] 2>
[junit4] 2> 3365249 INFO (SUITE-ManagedSchemaRoundRobinCloudTest-seed#[D755479BCC63C346]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=612, maxMBSortInHeap=7.432777821189891, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@f9a6d2f), locale=ar-QA, timezone=Iceland
[junit4] 2> NOTE: Linux 4.10.0-37-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=57156248,total=530579456
[junit4] 2> NOTE: All tests run in this JVM: [TestMacros, TestManagedSchema, ConnectionReuseTest, OverseerRolesTest, CdcrRequestHandlerTest, WrapperMergePolicyFactoryTest, DistribJoinFromCollectionTest, SolrCLIZkUtilsTest, TestShardHandlerFactory, TestExclusionRuleCollectionAccess, TestMissingGroups, TestConfigSets, DistributedExpandComponentTest, HdfsRecoveryZkTest, SystemInfoHandlerTest, SolrTestCaseJ4Test, XmlUpdateRequestHandlerTest, TestCSVResponseWriter, TestTolerantSearch, CoreMergeIndexesAdminHandlerTest, SearchRateTriggerTest, LoggingHandlerTest, HdfsThreadLeakTest, UtilsToolTest, TestAuthenticationFramework, TestCloudRecovery, TestDistributedGrouping, TimeZoneUtilsTest, PropertiesRequestHandlerTest, TestSolrCoreProperties, TestHashPartitioner, PluginInfoTest, TestHighFrequencyDictionaryFactory, TestSchemaResource, HdfsCollectionsAPIDistributedZkTest, TestXmlQParser, BigEndianAscendingWordSerializerTest, IndexSchemaTest, TemplateUpdateProcessorTest, TestSearchPerf, TestReRankQParserPlugin, SolrGraphiteReporterTest, DeleteNodeTest, SparseHLLTest, TolerantUpdateProcessorTest, TestSystemIdResolver, HdfsWriteToMultipleCollectionsTest, TriLevelCompositeIdRoutingTest, TestDeleteCollectionOnDownNodes, AnalysisErrorHandlingTest, HdfsDirectoryFactoryTest, TestMultiValuedNumericRangeQuery, DistributedFacetPivotLongTailTest, TestConfigsApi, AsyncCallRequestStatusResponseTest, TestLRUCache, TestSQLHandlerNonCloud, TestFunctionQuery, MoveReplicaHDFSFailoverTest, SimpleMLTQParserTest, TestCloudNestedDocsSort, LegacyCloudClusterPropTest, TestReplicaProperties, TestGeoJSONResponseWriter, TestUseDocValuesAsStored, TestTolerantUpdateProcessorCloud, TestSubQueryTransformer, ParsingFieldUpdateProcessorsTest, SortByFunctionTest, TestFuzzyAnalyzedSuggestions, SolrCoreCheckLockOnStartupTest, TestManagedResource, ClassificationUpdateProcessorFactoryTest, TestIntervalFaceting, CustomCollectionTest, ZkStateReaderTest, CSVRequestHandlerTest, ReturnFieldsTest, TestCoreDiscovery, ShardSplitTest, TestSolrXml, LeaderElectionTest, SpellPossibilityIteratorTest, TestTrackingShardHandlerFactory, UniqFieldsUpdateProcessorFactoryTest, TestBinaryResponseWriter, CollectionsAPIAsyncDistributedZkTest, TestComplexPhraseQParserPlugin, CopyFieldTest, TestSerializedLuceneMatchVersion, BufferStoreTest, TestTrie, AliasIntegrationTest, SolrSlf4jReporterTest, TestRealTimeGet, TestOverriddenPrefixQueryForCustomFieldType, MultiThreadedOCPTest, TestPKIAuthenticationPlugin, ChaosMonkeyNothingIsSafeTest, FullSolrCloudDistribCmdsTest, TestJsonFacets, TestPrepRecovery, AddSchemaFieldsUpdateProcessorFactoryTest, DateRangeFieldTest, MetricsConfigTest, TestZkChroot, RequestLoggingTest, NumberUtilsTest, TestIndexSearcher, TestLockTree, TestReload, TestCharFilters, TestConfigOverlay, TestNonDefinedSimilarityFactory, CdcrBootstrapTest, SuggesterWFSTTest, DistributedSpellCheckComponentTest, TestPartialUpdateDeduplication, SuggesterTest, TestQuerySenderListener, AutoscalingHistoryHandlerTest, TestSearcherReuse, TestLeaderElectionZkExpiry, RecoveryZkTest, ClusterStateUpdateTest, TestRandomDVFaceting, ShardRoutingCustomTest, TestDistributedSearch, TestRecovery, TermVectorComponentDistributedTest, TestCoreContainer, TestSolr4Spatial, SolrCoreTest, StatsComponentTest, SolrCmdDistributorTest, ConvertedLegacyTest, TestFiltering, TestStressLucene, TestCSVLoader, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestUpdate, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DistanceFunctionTest, TestSolrDeletionPolicy1, CacheHeaderTest, TestSurroundQueryParser, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestQueryTypes, TestOmitPositions, TermsComponentTest, MoreLikeThisHandlerTest, FastVectorHighlighterTest, JsonLoaderTest, TestPHPSerializedResponseWriter, TestComponentsName, TestLFUCache, AssignTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionStateFormat2Test, ConfigSetsAPITest, CreateCollectionCleanupTest, DeleteStatusTest, DistribDocExpirationUpdateProcessorTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderFailoverAfterPartitionTest, MoveReplicaHDFSTest, OverseerStatusTest, OverseerTaskQueueTest, RecoveryAfterSoftCommitTest, SSLMigrationTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, SolrXmlInZkTest, TestClusterProperties, TestCollectionAPI, TestConfigSetsAPIExclusivity, TestCryptoKeys, TestPullReplica, TestSkipOverseerOperations, TestStressInPlaceUpdates, HdfsAutoAddReplicasIntegrationTest, CdcrVersionReplicationTest, HdfsBasicDistributedZkTest, HdfsChaosMonkeyNothingIsSafeTest, HdfsChaosMonkeySafeLeaderTest, HdfsRecoverLeaseTest, HdfsTlogReplayBufferedWhileIndexingTest, HdfsUnloadDistributedZkTest, StressHdfsTest, RuleEngineTest, BlobRepositoryCloudTest, TestDynamicLoading, TestHdfsBackupRestoreCore, V2StandaloneTest, MetricsHandlerTest, SegmentsInfoRequestHandlerTest, StatsReloadRaceTest, TestCoreAdminApis, DistributedFacetExistsSmallTest, DistributedFacetPivotSmallAdvancedTest, DistributedSuggestComponentTest, SuggestComponentContextFilterQueryTest, TestDistributedStatsComponentCardinality, SolrJmxReporterTest, RegexBytesRefFilterTest, TestMacroExpander, TestGraphMLResponseWriter, TestJavabinTupleStreamParser, TestPushWriter, TestRawResponseWriter, TestRetrieveFieldsOptimizer, TestChildDocTransformer, TestSubQueryTransformerDistrib, TestManagedResourceStorage, TestBulkSchemaAPI, TestDynamicFieldResource, TestFieldCollectionResource, TestFieldTypeCollectionResource, TestFieldTypeResource, TestSchemaVersionResource, TestManagedStopFilterFactory, TestManagedSynonymFilterFactory, BadCopyFieldTest, BooleanFieldTest, ChangedSchemaMergeTest, CurrencyFieldTypeTest, ManagedSchemaRoundRobinCloudTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ManagedSchemaRoundRobinCloudTest -Dtests.seed=D755479BCC63C346 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar-QA -Dtests.timezone=Iceland -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J2 | ManagedSchemaRoundRobinCloudTest (suite) <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:36115/solr: create the collection time out:180s
[junit4] > at __randomizedtesting.SeedInfo.seed([D755479BCC63C346]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1104)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
[junit4] > at org.apache.solr.schema.ManagedSchemaRoundRobinCloudTest.setupCluster(ManagedSchemaRoundRobinCloudTest.java:50)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] Completed [744/750 (2!)] on J2 in 215.79s, 0 tests, 1 error <<< FAILURES!
[...truncated 47267 lines...]
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_144) - Build #
20934 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/20934/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed.
FAILED: org.apache.solr.cloud.ShardSplitTest.test
Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:43307/u
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:43307/u
at __randomizedtesting.SeedInfo.seed([6FE12D93B7B427A9:E7B5124919484A51]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:654)
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.sendRequest(CloudSolrClient.java:1104)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:883)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:816)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1668)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1607)
at org.apache.solr.cloud.ShardSplitTest.splitByRouteFieldTest(ShardSplitTest.java:677)
at org.apache.solr.cloud.ShardSplitTest.test(ShardSplitTest.java:101)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:993)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
... 53 more
FAILED: org.apache.solr.cloud.TestLocalFSCloudBackupRestore.test
Error Message:
There are still nodes recoverying - waited for 30 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 30 seconds
at __randomizedtesting.SeedInfo.seed([6FE12D93B7B427A9:E7B5124919484A51]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:185)
at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:289)
at org.apache.solr.cloud.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:140)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12236 lines...]
[junit4] Suite: org.apache.solr.cloud.TestLocalFSCloudBackupRestore
[junit4] 2> 730555 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/init-core-data-001
[junit4] 2> 730555 WARN (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 730556 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 730557 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 730558 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001
[junit4] 2> 730558 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 730559 INFO (Thread-1714) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 730559 INFO (Thread-1714) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 730563 ERROR (Thread-1714) [ ] 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> 730658 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41151
[junit4] 2> 730664 INFO (jetty-launcher-936-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 730664 INFO (jetty-launcher-936-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@57e5e01c{/solr,null,AVAILABLE}
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@142cfa39{/solr,null,AVAILABLE}
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@41a67545{SSL,[ssl, http/1.1]}{127.0.0.1:43333}
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-1) [ ] o.e.j.s.Server Started @732683ms
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2b6bbf6c{SSL,[ssl, http/1.1]}{127.0.0.1:46391}
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43333}
[junit4] 2> 730674 INFO (jetty-launcher-936-thread-2) [ ] o.e.j.s.Server Started @732683ms
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46391}
[junit4] 2> 730675 ERROR (jetty-launcher-936-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 730675 ERROR (jetty-launcher-936-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-17T13:04:46.013Z
[junit4] 2> 730675 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-11-17T13:04:46.013Z
[junit4] 2> 730680 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 730680 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 730687 INFO (jetty-launcher-936-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41151/solr
[junit4] 2> 730687 INFO (jetty-launcher-936-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41151/solr
[junit4] 2> 730709 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 730709 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46391_solr
[junit4] 2> 730709 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.c.Overseer Overseer (id=99019907786342406-127.0.0.1:46391_solr-n_0000000000) starting
[junit4] 2> 730716 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46391_solr
[junit4] 2> 730723 INFO (zkCallback-949-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 730730 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 730731 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 730733 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43333_solr
[junit4] 2> 730733 INFO (zkCallback-949-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 730736 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:43333_solr) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 730811 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730823 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730824 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730824 INFO (jetty-launcher-936-thread-2) [n:127.0.0.1:46391_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/.
[junit4] 2> 730832 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730837 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730837 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 730838 INFO (jetty-launcher-936-thread-1) [n:127.0.0.1:43333_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/.
[junit4] 2> 730853 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 730853 INFO (SUITE-TestLocalFSCloudBackupRestore-seed#[6FE12D93B7B427A9]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41151/solr ready
[junit4] 2> 730870 INFO (TEST-TestLocalFSCloudBackupRestore.test-seed#[6FE12D93B7B427A9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 730886 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf1&version=2&pullReplicas=0&property.customKey=customValue&maxShardsPerNode=6&router.field=shard_s&name=backuprestore&nrtReplicas=2&action=CREATE&numShards=2&tlogReplicas=1&wt=javabin and sendToOCPQueue=true
[junit4] 2> 730888 INFO (OverseerThreadFactory-2784-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.CreateCollectionCmd Create collection backuprestore
[junit4] 2> 730888 WARN (OverseerThreadFactory-2784-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 3 on collection backuprestore is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 730992 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"backuprestore_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43333/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 730993 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"backuprestore_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:46391/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 730993 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"backuprestore_shard1_replica_t4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43333/solr",
[junit4] 2> "type":"TLOG",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 730994 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"backuprestore_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:46391/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 730995 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"backuprestore_shard2_replica_n8",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:43333/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 730996 INFO (OverseerStateUpdate-99019907786342406-127.0.0.1:46391_solr-n_0000000000) [n:127.0.0.1:46391_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"backuprestore",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"backuprestore_shard2_replica_t10",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:46391/solr",
[junit4] 2> "type":"TLOG",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 731207 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin
[junit4] 2> 731207 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 731208 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node7&name=backuprestore_shard1_replica_t4&action=CREATE&numShards=2&shard=shard1&wt=javabin
[junit4] 2> 731232 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node5&name=backuprestore_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin
[junit4] 2> 731232 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 731236 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node11&name=backuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin
[junit4] 2> 731237 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node12&name=backuprestore_shard2_replica_t10&action=CREATE&numShards=2&shard=shard2&wt=javabin
[junit4] 2> 731237 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node9&name=backuprestore_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin
[junit4] 2> 731341 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:43333_solr) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 731342 INFO (zkCallback-949-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 731342 INFO (zkCallback-949-thread-2-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 732215 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732221 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.s.IndexSchema [backuprestore_shard1_replica_t4] Schema name=minimal
[junit4] 2> 732222 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732223 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_t4' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732225 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.core.backuprestore.shard1.replica_t4' (registry 'solr.core.backuprestore.shard1.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732225 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732225 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore [[backuprestore_shard1_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/backuprestore_shard1_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/./backuprestore_shard1_replica_t4/data/]
[junit4] 2> 732228 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732251 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n1] Schema name=minimal
[junit4] 2> 732254 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732256 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732257 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732257 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n1' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732257 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.core.backuprestore.shard1.replica_n1' (registry 'solr.core.backuprestore.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732258 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732258 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/backuprestore_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/./backuprestore_shard1_replica_n1/data/]
[junit4] 2> 732261 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732291 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n2] Schema name=minimal
[junit4] 2> 732293 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732294 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n2' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732294 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.core.backuprestore.shard1.replica_n2' (registry 'solr.core.backuprestore.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732294 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732294 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n8] Schema name=minimal
[junit4] 2> 732295 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/backuprestore_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/./backuprestore_shard1_replica_n2/data/]
[junit4] 2> 732295 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 732297 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732298 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n8' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732298 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43333.solr.core.backuprestore.shard2.replica_n8' (registry 'solr.core.backuprestore.shard2.replica_n8') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732298 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732298 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n8] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/backuprestore_shard2_replica_n8], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node1/./backuprestore_shard2_replica_n8/data/]
[junit4] 2> 732303 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n6] Schema name=minimal
[junit4] 2> 732305 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732305 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n6' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732305 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.core.backuprestore.shard2.replica_n6' (registry 'solr.core.backuprestore.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732305 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732305 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/backuprestore_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/./backuprestore_shard2_replica_n6/data/]
[junit4] 2> 732309 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.s.IndexSchema [backuprestore_shard2_replica_t10] Schema name=minimal
[junit4] 2> 732311 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732311 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732312 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 732312 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_t10' using configuration from collection backuprestore, trusted=true
[junit4] 2> 732312 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46391.solr.core.backuprestore.shard2.replica_t10' (registry 'solr.core.backuprestore.shard2.replica_t10') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6b5964c6
[junit4] 2> 732312 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 732313 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.SolrCore [[backuprestore_shard2_replica_t10] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/backuprestore_shard2_replica_t10], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.TestLocalFSCloudBackupRestore_6FE12D93B7B427A9-001/tempDir-001/node2/./backuprestore_shard2_replica_t10/data/]
[junit4] 2> 732313 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732313 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732327 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.s.SolrIndexSearcher Opening [Searcher@5131580f[backuprestore_shard1_replica_t4] main]
[junit4] 2> 732328 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732328 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732329 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732332 INFO (searcherExecutor-2789-thread-1-processing-n:127.0.0.1:43333_solr x:backuprestore_shard1_replica_t4 s:shard1 c:backuprestore r:core_node7) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore [backuprestore_shard1_replica_t4] Registered new searcher Searcher@5131580f[backuprestore_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732332 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526437457920
[junit4] 2> 732338 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=3 found=1 timeoutin=9999ms
[junit4] 2> 732343 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732343 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732344 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732344 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732345 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@36edace6[backuprestore_shard1_replica_n1] main]
[junit4] 2> 732346 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732346 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732346 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732347 INFO (searcherExecutor-2790-thread-1-processing-n:127.0.0.1:43333_solr x:backuprestore_shard1_replica_n1 s:shard1 c:backuprestore r:core_node3) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore [backuprestore_shard1_replica_n1] Registered new searcher Searcher@36edace6[backuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732347 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526453186560
[junit4] 2> 732368 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732368 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732369 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732369 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732370 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.s.SolrIndexSearcher Opening [Searcher@404d3524[backuprestore_shard2_replica_n8] main]
[junit4] 2> 732371 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732371 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732372 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732372 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732372 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732373 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732373 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732374 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.s.SolrIndexSearcher Opening [Searcher@4edf03f2[backuprestore_shard2_replica_t10] main]
[junit4] 2> 732375 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732375 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732376 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732376 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732377 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732377 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732377 INFO (searcherExecutor-2793-thread-1-processing-n:127.0.0.1:43333_solr x:backuprestore_shard2_replica_n8 s:shard2 c:backuprestore r:core_node11) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore [backuprestore_shard2_replica_n8] Registered new searcher Searcher@404d3524[backuprestore_shard2_replica_n8] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732377 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526484643840
[junit4] 2> 732378 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 732378 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 732378 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@6943102f[backuprestore_shard1_replica_n2] main]
[junit4] 2> 732379 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 732379 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 732379 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732379 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732379 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732380 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732380 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526487789568
[junit4] 2> 732380 INFO (searcherExecutor-2796-thread-1-processing-n:127.0.0.1:46391_solr x:backuprestore_shard2_replica_t10 s:shard2 c:backuprestore r:core_node12) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.SolrCore [backuprestore_shard2_replica_t10] Registered new searcher Searcher@4edf03f2[backuprestore_shard2_replica_t10] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732380 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@24ed51e9[backuprestore_shard2_replica_n6] main]
[junit4] 2> 732380 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526487789568
[junit4] 2> 732381 INFO (searcherExecutor-2792-thread-1-processing-n:127.0.0.1:46391_solr x:backuprestore_shard1_replica_n2 s:shard1 c:backuprestore r:core_node5) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore [backuprestore_shard1_replica_n2] Registered new searcher Searcher@6943102f[backuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732381 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 732381 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 732382 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 732382 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1584318526489886720
[junit4] 2> 732384 INFO (searcherExecutor-2794-thread-1-processing-n:127.0.0.1:46391_solr x:backuprestore_shard2_replica_n6 s:shard2 c:backuprestore r:core_node9) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.SolrCore [backuprestore_shard2_replica_n6] Registered new searcher Searcher@24ed51e9[backuprestore_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 732384 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=3 found=2 timeoutin=9999ms
[junit4] 2> 732485 INFO (zkCallback-949-thread-1-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 732485 INFO (zkCallback-949-thread-2-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 732486 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:43333_solr) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 732838 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 732838 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 732838 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43333/solr/backuprestore_shard1_replica_t4/
[junit4] 2> 732838 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_t4 url=https://127.0.0.1:43333/solr START replicas=[https://127.0.0.1:43333/solr/backuprestore_shard1_replica_n1/, https://127.0.0.1:46391/solr/backuprestore_shard1_replica_n2/] nUpdates=100
[junit4] 2> 732844 INFO (qtp732346074-6344) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.S.Request [backuprestore_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 732844 INFO (qtp336439182-6338) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.S.Request [backuprestore_shard1_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 732885 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 732885 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 732885 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/
[junit4] 2> 732885 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n8 url=https://127.0.0.1:43333/solr START replicas=[https://127.0.0.1:46391/solr/backuprestore_shard2_replica_n6/, https://127.0.0.1:46391/solr/backuprestore_shard2_replica_t10/] nUpdates=100
[junit4] 2> 732890 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.S.Request [backuprestore_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 732893 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.S.Request [backuprestore_shard2_replica_t10] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 733139 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_t4 url=https://127.0.0.1:43333/solr DONE. We have no versions. sync failed.
[junit4] 2> 733139 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 733139 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 733139 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 733139 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ZkController backuprestore_shard1_replica_t4 stopping background replication from leader
[junit4] 2> 733141 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43333/solr/backuprestore_shard1_replica_t4/ shard1
[junit4] 2> 733185 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n8 url=https://127.0.0.1:43333/solr DONE. We have no versions. sync failed.
[junit4] 2> 733185 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 733185 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 733185 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 733187 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/ shard2
[junit4] 2> 733288 INFO (zkCallback-949-thread-2-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 733288 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:43333_solr) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 733288 INFO (zkCallback-949-thread-3-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 733291 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 733292 INFO (qtp336439182-6285) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node7&name=backuprestore_shard1_replica_t4&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2085
[junit4] 2> 733337 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 733338 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node11&name=backuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2102
[junit4] 2> 733354 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2146
[junit4] 2> 733383 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.ZkController backuprestore_shard2_replica_t10 starting background replication from leader
[junit4] 2> 733383 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
[junit4] 2> 733384 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
[junit4] 2> 733384 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 733385 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node12&name=backuprestore_shard2_replica_t10&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2148
[junit4] 2> 733385 INFO (qtp732346074-6270) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node9&name=backuprestore_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2148
[junit4] 2> 733386 INFO (qtp732346074-6283) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node5&name=backuprestore_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2154
[junit4] 2> 733388 INFO (qtp336439182-6271) [n:127.0.0.1:43333_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> 733486 INFO (zkCallback-949-thread-2-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 733486 INFO (zkCallback-947-thread-1-processing-n:127.0.0.1:43333_solr) [n:127.0.0.1:43333_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 733486 INFO (zkCallback-949-thread-3-processing-n:127.0.0.1:46391_solr) [n:127.0.0.1:46391_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
[junit4] 2> 734388 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf1&version=2&pullReplicas=0&property.customKey=customValue&maxShardsPerNode=6&router.field=shard_s&name=backuprestore&nrtReplicas=2&action=CREATE&numShards=2&tlogReplicas=1&wt=javabin} status=0 QTime=3501
[junit4] 2> 734405 INFO (qtp732346074-6275) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&wt=javabin&version=2}{add=[0 (1584318528597524480), 1 (1584318528600670208), 2 (1584318528600670209), 3 (1584318528600670210), 4 (1584318528600670211), 5 (1584318528601718784), 6 (1584318528601718785), 7 (1584318528601718786), 8 (1584318528601718787), 9 (1584318528601718788), ... (56 adds)]} 0 4
[junit4] 2> 734408 INFO (qtp732346074-6344) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_t10] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&wt=javabin&version=2}{add=[0 (1584318528597524480), 1 (1584318528600670208), 2 (1584318528600670209), 3 (1584318528600670210), 4 (1584318528600670211), 5 (1584318528601718784), 6 (1584318528601718785), 7 (1584318528601718786), 8 (1584318528601718787), 9 (1584318528601718788), ... (56 adds)]} 0 2
[junit4] 2> 734409 INFO (qtp336439182-6282) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n8] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1584318528597524480), 1 (1584318528600670208), 2 (1584318528600670209), 3 (1584318528600670210), 4 (1584318528600670211), 5 (1584318528601718784), 6 (1584318528601718785), 7 (1584318528601718786), 8 (1584318528601718787), 9 (1584318528601718788), ... (56 adds)]} 0 16
[junit4] 2> 734411 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1584318528617447424,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 734411 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 734412 INFO (qtp732346074-6363) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1584318528618496000,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 734412 INFO (qtp732346074-6363) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@68436a9b commitCommandVersion:1584318528618496000
[junit4] 2> 734413 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 734413 INFO (qtp732346074-6277) [n:127.0.0.1:46391_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 734414 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1584318528620593152,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 734416 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 734419 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 734419 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node7 x:backuprestore_shard1_replica_t4] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_t4] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 5
[junit4] 2> 734419 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1584318528625836032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 734420 INFO (qtp732346074-6281) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.u.TestInjection Start waiting for replica in sync with leader
[junit4] 2> 734420 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 734420 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 734420 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 734422 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1584318528628981760,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 734422 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@c3c3463 commitCommandVersion:1584318528628981760
[junit4] 2> 734425 INFO (qtp336439182-6276) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 734433 INFO (qtp732346074-6363) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@4f3be44[backuprestore_shard2_replica_n6] main]
[junit4] 2> 734433 INFO (qtp732346074-6363) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 734434 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.s.SolrIndexSearcher Opening [Searcher@a4cb50a[backuprestore_shard2_replica_n8] main]
[junit4] 2> 734435 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 734435 INFO (searcherExecutor-2794-thread-1-processing-n:127.0.0.1:46391_solr x:backuprestore_shard2_replica_n6 s:shard2 c:backuprestore r:core_node9) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.c.SolrCore [backuprestore_shard2_replica_n6] Registered new searcher Searcher@4f3be44[backuprestore_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C56)))}
[junit4] 2> 734436 INFO (qtp732346074-6363) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 23
[junit4] 2> 734437 INFO (searcherExecutor-2793-thread-1-processing-n:127.0.0.1:43333_solr x:backuprestore_shard2_replica_n8 s:shard2 c:backuprestore r:core_node11) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore [backuprestore_shard2_replica_n8] Registered new searcher Searcher@a4cb50a[backuprestore_shard2_replica_n8] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C56)))}
[junit4] 2> 734437 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.u.p.LogUpdateProcessorFactory [backuprestore_shard2_replica_n8] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 15
[junit4] 2> 734512 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:43333/solr/backuprestore_shard2_replica_n8/
[junit4] 2> 734515 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 734515 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 734516 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Master's version: 1510923889760
[junit4] 2> 734516 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 734516 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 734516 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 734517 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 734517 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Number of files in latest index in master: 18
[junit4] 2> 734518 INFO (indexFetcher-2820-thread-1) [n:127.0.0.1:46391_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t10] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1bbee608 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@139b7669)
[junit4] 2> 734518 INFO (qtp336439182-6276) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734520 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneFixedGap_0.tib&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734522 INFO (qtp336439182-6338) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734523 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734524 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneFixedGap_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734525 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FST50_0.tfp&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734526 INFO (qtp336439182-6276) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734527 INFO (qtp336439182-6274) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneFixedGap_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734528 INFO (qtp336439182-6338) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_LuceneFixedGap_0.tii&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734529 INFO (qtp336439182-6271) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.dii&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734566 INFO (qtp336439182-6284) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_n8] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FST50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 734567 INFO (qtp336439182-6341) [n:127.0.0.1:43333_solr c:backuprestore s:shard2 r:core_node11 x:backuprestore_shard2_replica_n8] o.a.s.c.S.Request [backuprestore_shard2_replica_
[...truncated too long message...]
nager Closing metric reporters for registry=solr.collection.collection1.shard1.leader, tag=1916134898
[junit4] 2> 1546387 INFO (zkCallback-946-thread-1-processing-n:127.0.0.1:43787_u) [n:127.0.0.1:43787_u ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/shardSplitWithRule/state.json] for collection [shardSplitWithRule] has occurred - updating... (live nodes size: [0])
[junit4] 2> 1546387 INFO (zkCallback-946-thread-5-processing-n:127.0.0.1:43787_u) [n:127.0.0.1:43787_u ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/shardSplitWithRule/state.json] for collection [shardSplitWithRule] has occurred - updating... (live nodes size: [0])
[junit4] 2> 1546388 INFO (zkCallback-946-thread-5-processing-n:127.0.0.1:43787_u) [n:127.0.0.1:43787_u ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [0])
[junit4] 2> 1551253 INFO (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.c.RecoveryStrategy Finished recovery process, successful=[false]
[junit4] 2> 1551253 INFO (zkCallback-946-thread-5-processing-n:127.0.0.1:43787_u) [n:127.0.0.1:43787_u ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/shardSplitWithRule/state.json] for collection [shardSplitWithRule] has occurred - updating... (live nodes size: [0])
[junit4] 2> 1551253 INFO (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.c.SolrCore [shardSplitWithRule_shard1_1_replica0] CLOSING SolrCore org.apache.solr.core.SolrCore@2827a164
[junit4] 2> 1551253 INFO (zkCallback-946-thread-2-processing-n:127.0.0.1:43787_u) [n:127.0.0.1:43787_u ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/shardSplitWithRule/state.json] for collection [shardSplitWithRule] has occurred - updating... (live nodes size: [0])
[junit4] 2> 1551253 INFO (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.shardSplitWithRule.shard1_1.replica0, tag=673685860
[junit4] 2> 1551254 INFO (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@45ca9205: rootName = null, domain = solr.core.shardSplitWithRule.shard1_1.replica0, service url = null, agent id = null] for registry solr.core.shardSplitWithRule.shard1_1.replica0 / com.codahale.metrics.MetricRegistry@26aa3db6
[junit4] 2> 1551265 INFO (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.shardSplitWithRule.shard1_1.leader, tag=673685860
[junit4] 2> 1551266 WARN (recoveryExecutor-944-thread-1-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.c.RecoveryStrategy Stopping recovery for core=[shardSplitWithRule_shard1_1_replica0] coreNodeName=[core_node9]
[junit4] 2> 1551268 WARN (updateExecutor-943-thread-2-processing-n:127.0.0.1:43787_u x:shardSplitWithRule_shard1_1_replica0 s:shard1_1 c:shardSplitWithRule r:core_node9) [n:127.0.0.1:43787_u c:shardSplitWithRule s:shard1_1 r:core_node9 x:shardSplitWithRule_shard1_1_replica0] o.a.s.u.DefaultSolrCoreState Skipping recovery because Solr is shutdown
[junit4] 2> 1551269 INFO (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] o.a.s.c.Overseer Overseer (id=99019957555167250-127.0.0.1:43787_u-n_0000000004) closing
[junit4] 2> 1551269 INFO (OverseerStateUpdate-99019957555167250-127.0.0.1:43787_u-n_0000000004) [n:127.0.0.1:43787_u ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43787_u
[junit4] 2> 1551269 WARN (OverseerAutoScalingTriggerThread-99019957555167250-127.0.0.1:43787_u-n_0000000004) [n:127.0.0.1:43787_u ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1551273 INFO (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@49048e2f{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1551273 INFO (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5f5bacb4{/u,null,UNAVAILABLE}
[junit4] 2> 1551274 INFO (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] o.a.s.c.ChaosMonkey monkey: stop jetty! 37077
[junit4] 2> 1551274 ERROR (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] 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> 1551275 INFO (TEST-ShardSplitTest.testSplitShardWithRule-seed#[6FE12D93B7B427A9]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41633 41633
[junit4] 2> 1561344 INFO (Thread-1253) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:41633 41633
[junit4] 2> 1561344 WARN (Thread-1253) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 5 /solr/security.json
[junit4] 2> 5 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 57 /solr/collections/shardSplitWithRule/state.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 5 /solr/autoscaling.json
[junit4] 2> 4 /solr/collections/collection1/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 5 /solr/overseer/queue
[junit4] 2> 5 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2> 5 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ShardSplitTest_6FE12D93B7B427A9-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {rnd_b=FST50, a_t=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=FST50}, docValues:{rnd_b=DocValuesFormat(name=Lucene70), _version_=DocValuesFormat(name=Asserting), n_ti=DocValuesFormat(name=Lucene70), a_t=DocValuesFormat(name=Lucene70), a_i=DocValuesFormat(name=Lucene70), id=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1998, maxMBSortInHeap=6.032348015693211, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@259c93a3), locale=es-CO, timezone=Africa/Harare
[junit4] 2> NOTE: Linux 4.10.0-37-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=204460968,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [MetricsConfigTest, TestZkAclsWithHadoopAuth, ComputePlanActionTest, TestLockTree, TestBinaryResponseWriter, TestSerializedLuceneMatchVersion, TestStressInPlaceUpdates, ReplaceNodeTest, TestSearcherReuse, HdfsDirectoryFactoryTest, LeaderFailureAfterFreshStartTest, TestDocTermOrds, ManagedSchemaRoundRobinCloudTest, NumberUtilsTest, TestLMJelinekMercerSimilarityFactory, ConjunctionSolrSpellCheckerTest, TestRTimerTree, SolrSlf4jReporterTest, TestMacros, DirectSolrConnectionTest, FullHLLTest, StatsReloadRaceTest, TestUnifiedSolrHighlighter, TestInitQParser, TestPKIAuthenticationPlugin, TestCSVResponseWriter, TestLRUCache, TestTolerantUpdateProcessorCloud, ClassificationUpdateProcessorFactoryTest, TestGeoJSONResponseWriter, TestNumericTerms64, TestFieldCacheSort, TestManagedSchema, AlternateDirectoryTest, TestSQLHandlerNonCloud, TolerantUpdateProcessorTest, DateRangeFieldTest, QueryElevationComponentTest, HdfsBasicDistributedZkTest, TestPrepRecovery, TestXmlQParser, BasicAuthStandaloneTest, TestMultiValuedNumericRangeQuery, TestReqParamsAPI, DeleteNodeTest, TestGroupingSearch, TestSearchPerf, UtilsToolTest, SortByFunctionTest, TestConfigOverlay, DirectSolrSpellCheckerTest, TestDistributedGrouping, TestRealTimeGet, TestCloudSchemaless, AnalyticsQueryTest, RuleEngineTest, ChaosMonkeyNothingIsSafeTest, TestFieldCacheWithThreads, ShardSplitTest]
[junit4] Completed [445/750 (2!)] on J2 in 977.32s, 5 tests, 1 error <<< FAILURES!
[...truncated 48338 lines...]