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 2016/11/06 19:38:22 UTC
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_102) - Build #
18222 - Still Failing!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18222/
Java: 64bit/jdk1.8.0_102 -XX:-UseCompressedOops -XX:+UseG1GC
All tests passed
Build Log:
[...truncated 24383 lines...]
-validate-source-patterns:
[source-patterns] tabs instead spaces: solr/example/files/conf/update-script.js
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 1 violations in source files (tabs instead spaces).
Total time: 67 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS-EA] Lucene-Solr-master-Linux (32bit/jdk-9-ea+140) - Build
# 18226 - Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18226/
Java: 32bit/jdk-9-ea+140 -client -XX:+UseParallelGC
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CollectionsAPIDistributedZkTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest: 1) Thread[id=5086, name=OverseerHdfsCoreFailoverThread-96896097677672458-127.0.0.1:44015_solr-n_0000000003, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.] at java.lang.Thread.sleep(java.base@9-ea/Native Method) at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137) at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest:
1) Thread[id=5086, name=OverseerHdfsCoreFailoverThread-96896097677672458-127.0.0.1:44015_solr-n_0000000003, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
at java.lang.Thread.sleep(java.base@9-ea/Native Method)
at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
at __randomizedtesting.SeedInfo.seed([EF734053447575D6]:0)
Build Log:
[...truncated 11437 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/init-core-data-001
[junit4] 2> 660367 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 660370 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001
[junit4] 2> 660370 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 660370 INFO (Thread-1151) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 660371 INFO (Thread-1151) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 660471 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:45207
[junit4] 2> 660480 INFO (jetty-launcher-828-thread-3) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 660480 INFO (jetty-launcher-828-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 660480 INFO (jetty-launcher-828-thread-4) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 660480 INFO (jetty-launcher-828-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 660481 INFO (jetty-launcher-828-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@448eed{/solr,null,AVAILABLE}
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@98bc33{/solr,null,AVAILABLE}
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.e.j.s.ServerConnector Started ServerConnector@2f883a{SSL,[ssl, http/1.1]}{127.0.0.1:38755}
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.e.j.s.Server Started @662071ms
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38755}
[junit4] 2> 660482 ERROR (jetty-launcher-828-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 660482 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-07T11:11:55.552918Z
[junit4] 2> 660484 INFO (jetty-launcher-828-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@14ff833{SSL,[ssl, http/1.1]}{127.0.0.1:44015}
[junit4] 2> 660484 INFO (jetty-launcher-828-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@132f81c{/solr,null,AVAILABLE}
[junit4] 2> 660484 INFO (jetty-launcher-828-thread-2) [ ] o.e.j.s.Server Started @662073ms
[junit4] 2> 660484 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44015}
[junit4] 2> 660484 INFO (jetty-launcher-828-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@664ad3{/solr,null,AVAILABLE}
[junit4] 2> 660485 ERROR (jetty-launcher-828-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.e.j.s.ServerConnector Started ServerConnector@70f407{SSL,[ssl, http/1.1]}{127.0.0.1:45330}
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-07T11:11:55.555218Z
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.e.j.s.Server Started @662074ms
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@150669c{SSL,[ssl, http/1.1]}{127.0.0.1:46068}
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45330}
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-1) [ ] o.e.j.s.Server Started @662074ms
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46068}
[junit4] 2> 660485 ERROR (jetty-launcher-828-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 660485 ERROR (jetty-launcher-828-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-07T11:11:55.555711Z
[junit4] 2> 660485 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 660486 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 660486 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-11-07T11:11:55.556328Z
[junit4] 2> 660486 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 660487 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 660488 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 660491 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 660491 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1583e7cca330001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2> 660498 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45207/solr
[junit4] 2> 660501 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45207/solr
[junit4] 2> 660502 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45207/solr
[junit4] 2> 660503 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45207/solr
[junit4] 2> 660504 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1583e7cca330008, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2> 660518 INFO (jetty-launcher-828-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46068_solr
[junit4] 2> 660518 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38755_solr
[junit4] 2> 660518 INFO (jetty-launcher-828-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45330_solr
[junit4] 2> 660519 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 660519 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 660519 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.c.Overseer Overseer (id=96896097677672459-127.0.0.1:38755_solr-n_0000000000) starting
[junit4] 2> 660520 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 660520 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 660520 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 660524 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 660525 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 660525 INFO (jetty-launcher-828-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44015_solr
[junit4] 2> 660526 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 660526 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 660526 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 660531 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 660533 INFO (jetty-launcher-828-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38755_solr
[junit4] 2> 660534 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 660534 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 660534 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 660536 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 660545 INFO (jetty-launcher-828-thread-2) [ ] 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.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/.
[junit4] 2> 660549 INFO (jetty-launcher-828-thread-3) [ ] 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.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node3/.
[junit4] 2> 660557 INFO (jetty-launcher-828-thread-4) [ ] 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.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node4/.
[junit4] 2> 660563 INFO (jetty-launcher-828-thread-1) [ ] 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.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node1/.
[junit4] 2> 660568 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 660608 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF734053447575D6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
[junit4] 2> 660608 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF734053447575D6]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 660650 INFO (qtp16474945-4727) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=unknown_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 660651 INFO (OverseerThreadFactory-2104-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 660652 ERROR (OverseerThreadFactory-2104-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: unknown_collection operation: delete failed:org.apache.solr.common.SolrException: Could not find collection : unknown_collection
[junit4] 2> at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:193)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:843)
[junit4] 2> at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:81)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@9-ea/ThreadPoolExecutor.java:1161)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@9-ea/ThreadPoolExecutor.java:635)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2>
[junit4] 2> 660654 INFO (qtp16474945-4727) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=unknown_collection&action=DELETE&wt=javabin&version=2} status=400 QTime=4
[junit4] 2> 660655 INFO (qtp16474945-4728) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 660657 INFO (OverseerThreadFactory-2104-thread-2) [ ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete
[junit4] 2> 660657 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 660763 INFO (qtp16474945-4718) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
[junit4] 2> 660791 INFO (qtp31521719-4740) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
[junit4] 2> 660894 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 660894 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 661769 INFO (qtp16474945-4718) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 661774 INFO (qtp16474945-4718) [ ] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica2] Schema name=minimal
[junit4] 2> 661775 INFO (qtp16474945-4718) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 661776 INFO (qtp16474945-4718) [ ] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica2' using configuration from collection acollectionafterbaddelete
[junit4] 2> 661776 INFO (qtp16474945-4718) [ ] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node4/./acollectionafterbaddelete_shard1_replica2/data/]
[junit4] 2> 661782 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 661782 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 661786 INFO (qtp16474945-4718) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 661786 INFO (qtp16474945-4718) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 661786 INFO (qtp16474945-4718) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b3450[acollectionafterbaddelete_shard1_replica2] main]
[junit4] 2> 661787 INFO (qtp16474945-4718) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 661787 INFO (qtp16474945-4718) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 661787 INFO (qtp16474945-4718) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 661787 INFO (searcherExecutor-2113-thread-1) [ ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] Registered new searcher Searcher@3b3450[acollectionafterbaddelete_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 661787 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337564325445632
[junit4] 2> 661791 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 661797 INFO (qtp31521719-4740) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 661802 INFO (qtp31521719-4740) [ ] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica1] Schema name=minimal
[junit4] 2> 661803 INFO (qtp31521719-4740) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 661804 INFO (qtp31521719-4740) [ ] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica1' using configuration from collection acollectionafterbaddelete
[junit4] 2> 661804 INFO (qtp31521719-4740) [ ] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/acollectionafterbaddelete_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/./acollectionafterbaddelete_shard1_replica1/data/]
[junit4] 2> 661811 INFO (qtp31521719-4740) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 661811 INFO (qtp31521719-4740) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 661815 INFO (qtp31521719-4740) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 661815 INFO (qtp31521719-4740) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 661815 INFO (qtp31521719-4740) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@16e73f4[acollectionafterbaddelete_shard1_replica1] main]
[junit4] 2> 661816 INFO (qtp31521719-4740) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 661816 INFO (qtp31521719-4740) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 661816 INFO (qtp31521719-4740) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 661816 INFO (searcherExecutor-2118-thread-1) [ ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] Registered new searcher Searcher@16e73f4[acollectionafterbaddelete_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 661816 INFO (qtp31521719-4740) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337564355854336
[junit4] 2> 661892 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 661892 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662291 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 662291 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 662292 INFO (qtp16474945-4718) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:38755/solr/acollectionafterbaddelete_shard1_replica2/
[junit4] 2> 662292 INFO (qtp16474945-4718) [ ] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=https://127.0.0.1:38755/solr START replicas=[https://127.0.0.1:44015/solr/acollectionafterbaddelete_shard1_replica1/] nUpdates=100
[junit4] 2> 662292 INFO (qtp16474945-4718) [ ] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=https://127.0.0.1:38755/solr DONE. We have no versions. sync failed.
[junit4] 2> 662295 INFO (qtp31521719-4739) [ ] o.a.s.c.S.Request [acollectionafterbaddelete_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 662295 INFO (qtp16474945-4718) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 662295 INFO (qtp16474945-4718) [ ] 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> 662297 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:38755/solr/acollectionafterbaddelete_shard1_replica2/ shard1
[junit4] 2> 662398 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662398 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662447 INFO (qtp16474945-4718) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 662450 INFO (qtp16474945-4718) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=1688
[junit4] 2> 662549 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662549 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662822 INFO (qtp31521719-4740) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=2030
[junit4] 2> 662823 INFO (qtp16474945-4728) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 662921 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 662921 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 663824 INFO (qtp16474945-4728) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3168
[junit4] 2> 663826 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF734053447575D6]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDeleteNonExistentCollection
[junit4] 2> 663845 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[EF734053447575D6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
[junit4] 2> 663845 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[EF734053447575D6]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 663846 INFO (qtp16474945-4731) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 663847 INFO (OverseerThreadFactory-2104-thread-3) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 663847 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 663848 INFO (qtp31521719-4713) [ ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@12535ab
[junit4] 2> 663848 INFO (qtp16474945-4714) [ ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@e98fcd
[junit4] 2> 663860 INFO (qtp31521719-4713) [ ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
[junit4] 2> 663861 INFO (qtp31521719-4713) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 663862 WARN (zkCallback-847-thread-1) [ ] o.a.s.c.LeaderElector Our node is no longer in line to be leader
[junit4] 2> 663862 INFO (qtp16474945-4714) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=15
[junit4] 2> 664565 INFO (qtp16474945-4731) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2} status=0 QTime=719
[junit4] 2> 664566 INFO (qtp16474945-4727) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 664572 INFO (OverseerThreadFactory-2104-thread-4) [ ] o.a.s.c.CreateCollectionCmd Create collection addReplicaColl
[junit4] 2> 664572 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 664774 INFO (qtp16474945-4718) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 664775 INFO (qtp31521719-4738) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 664813 INFO (qtp15093928-4746) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 664815 INFO (qtp27562334-4712) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 664918 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 664918 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 664918 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 664918 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 665781 INFO (qtp16474945-4718) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 665782 INFO (qtp31521719-4738) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 665797 INFO (qtp16474945-4718) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
[junit4] 2> 665798 INFO (qtp31521719-4738) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
[junit4] 2> 665798 INFO (qtp16474945-4718) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 665799 INFO (qtp16474945-4718) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using configuration from collection addReplicaColl
[junit4] 2> 665799 INFO (qtp31521719-4738) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 665800 INFO (qtp16474945-4718) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node4/addReplicaColl_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node4/./addReplicaColl_shard1_replica1/data/]
[junit4] 2> 665800 INFO (qtp31521719-4738) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica1' using configuration from collection addReplicaColl
[junit4] 2> 665800 INFO (qtp31521719-4738) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/addReplicaColl_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/./addReplicaColl_shard2_replica1/data/]
[junit4] 2> 665807 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 665807 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 665807 INFO (qtp31521719-4738) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 665807 INFO (qtp31521719-4738) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 665811 INFO (qtp16474945-4718) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 665811 INFO (qtp16474945-4718) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 665811 INFO (qtp31521719-4738) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 665811 INFO (qtp31521719-4738) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 665811 INFO (qtp16474945-4718) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1049238[addReplicaColl_shard1_replica1] main]
[junit4] 2> 665811 INFO (qtp31521719-4738) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1299da8[addReplicaColl_shard2_replica1] main]
[junit4] 2> 665812 INFO (qtp31521719-4738) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 665812 INFO (qtp16474945-4718) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 665812 INFO (qtp31521719-4738) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 665812 INFO (qtp16474945-4718) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 665812 INFO (qtp31521719-4738) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 665812 INFO (qtp16474945-4718) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 665812 INFO (searcherExecutor-2124-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard2_replica1] Registered new searcher Searcher@1299da8[addReplicaColl_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 665812 INFO (searcherExecutor-2123-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica1] Registered new searcher Searcher@1049238[addReplicaColl_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 665812 INFO (qtp31521719-4738) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337568545964032
[junit4] 2> 665812 INFO (qtp16474945-4718) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337568545964032
[junit4] 2> 665817 INFO (qtp31521719-4738) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 665817 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 665822 INFO (qtp27562334-4712) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 665822 INFO (qtp15093928-4746) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 665826 INFO (qtp15093928-4746) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
[junit4] 2> 665826 INFO (qtp27562334-4712) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
[junit4] 2> 665829 INFO (qtp15093928-4746) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 665829 INFO (qtp27562334-4712) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 665829 INFO (qtp27562334-4712) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using configuration from collection addReplicaColl
[junit4] 2> 665829 INFO (qtp15093928-4746) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using configuration from collection addReplicaColl
[junit4] 2> 665830 INFO (qtp15093928-4746) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node1/addReplicaColl_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node1/./addReplicaColl_shard1_replica2/data/]
[junit4] 2> 665830 INFO (qtp27562334-4712) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node3/addReplicaColl_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node3/./addReplicaColl_shard2_replica2/data/]
[junit4] 2> 665836 INFO (qtp27562334-4712) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 665836 INFO (qtp27562334-4712) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 665836 INFO (qtp15093928-4746) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 665836 INFO (qtp15093928-4746) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 665841 INFO (qtp27562334-4712) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 665841 INFO (qtp27562334-4712) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 665842 INFO (qtp15093928-4746) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 665842 INFO (qtp15093928-4746) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 665842 INFO (qtp27562334-4712) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@17d0371[addReplicaColl_shard2_replica2] main]
[junit4] 2> 665842 INFO (qtp15093928-4746) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@15091c3[addReplicaColl_shard1_replica2] main]
[junit4] 2> 665842 INFO (qtp27562334-4712) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 665842 INFO (qtp15093928-4746) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 665842 INFO (qtp27562334-4712) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 665842 INFO (qtp15093928-4746) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 665843 INFO (qtp27562334-4712) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 665843 INFO (qtp15093928-4746) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 665843 INFO (searcherExecutor-2133-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard2_replica2] Registered new searcher Searcher@17d0371[addReplicaColl_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 665843 INFO (searcherExecutor-2134-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica2] Registered new searcher Searcher@15091c3[addReplicaColl_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 665843 INFO (qtp27562334-4712) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337568578469888
[junit4] 2> 665843 INFO (qtp15093928-4746) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337568578469888
[junit4] 2> 665920 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 665920 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 665920 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 665920 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666317 INFO (qtp31521719-4738) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 666317 INFO (qtp31521719-4738) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 666317 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 666318 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 666318 INFO (qtp31521719-4738) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:44015/solr/addReplicaColl_shard2_replica1/
[junit4] 2> 666318 INFO (qtp16474945-4718) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica1/
[junit4] 2> 666318 INFO (qtp31521719-4738) [ ] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard2_replica1 url=https://127.0.0.1:44015/solr START replicas=[https://127.0.0.1:45330/solr/addReplicaColl_shard2_replica2/] nUpdates=100
[junit4] 2> 666318 INFO (qtp16474945-4718) [ ] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard1_replica1 url=https://127.0.0.1:38755/solr START replicas=[https://127.0.0.1:46068/solr/addReplicaColl_shard1_replica2/] nUpdates=100
[junit4] 2> 666318 INFO (qtp16474945-4718) [ ] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard1_replica1 url=https://127.0.0.1:38755/solr DONE. We have no versions. sync failed.
[junit4] 2> 666318 INFO (qtp31521719-4738) [ ] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard2_replica1 url=https://127.0.0.1:44015/solr DONE. We have no versions. sync failed.
[junit4] 2> 666322 INFO (qtp27562334-4715) [ ] o.a.s.c.S.Request [addReplicaColl_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 666322 INFO (qtp15093928-4722) [ ] o.a.s.c.S.Request [addReplicaColl_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 666322 INFO (qtp31521719-4738) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 666322 INFO (qtp16474945-4718) [ ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 666322 INFO (qtp31521719-4738) [ ] 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> 666322 INFO (qtp16474945-4718) [ ] 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> 666324 INFO (qtp31521719-4738) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:44015/solr/addReplicaColl_shard2_replica1/ shard2
[junit4] 2> 666324 INFO (qtp16474945-4718) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica1/ shard1
[junit4] 2> 666426 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666426 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666426 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666426 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666475 INFO (qtp31521719-4738) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 666475 INFO (qtp16474945-4718) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 666478 INFO (qtp16474945-4718) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=1703
[junit4] 2> 666478 INFO (qtp31521719-4738) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2} status=0 QTime=1704
[junit4] 2> 666578 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666578 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666578 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666578 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666850 INFO (qtp27562334-4712) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2} status=0 QTime=2035
[junit4] 2> 666850 INFO (qtp15093928-4746) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=2036
[junit4] 2> 666851 INFO (qtp16474945-4727) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 666950 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666950 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666950 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 666950 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 667852 INFO (qtp16474945-4727) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3285
[junit4] 2> 667854 INFO (qtp16474945-4728) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:46068_solr&action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 667855 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd addReplica() : {
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "node":"127.0.0.1:46068_solr",
[junit4] 2> "shard":"shard1",
[junit4] 2> "operation":"addreplica"}
[junit4] 2> 667856 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 667856 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:46068_solr for creating new replica
[junit4] 2> 667857 INFO (qtp15093928-4716) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica3&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 667960 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 667960 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 667961 INFO (zkCallback-848-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 667960 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 668864 INFO (qtp15093928-4716) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 668868 INFO (qtp15093928-4716) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica3] Schema name=minimal
[junit4] 2> 668869 INFO (qtp15093928-4716) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 668870 INFO (qtp15093928-4716) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica3' using configuration from collection addReplicaColl
[junit4] 2> 668870 INFO (qtp15093928-4716) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node1/addReplicaColl_shard1_replica3], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node1/./addReplicaColl_shard1_replica3/data/]
[junit4] 2> 668876 INFO (qtp15093928-4716) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 668876 INFO (qtp15093928-4716) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 668880 INFO (qtp15093928-4716) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 668880 INFO (qtp15093928-4716) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 668881 INFO (qtp15093928-4716) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@c630f3[addReplicaColl_shard1_replica3] main]
[junit4] 2> 668881 INFO (qtp15093928-4716) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 668881 INFO (qtp15093928-4716) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 668881 INFO (qtp15093928-4716) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 668882 INFO (searcherExecutor-2143-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica3] Registered new searcher Searcher@c630f3[addReplicaColl_shard1_replica3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 668882 INFO (qtp15093928-4716) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337571765092352
[junit4] 2> 668885 INFO (qtp15093928-4716) [ ] o.a.s.c.ZkController Core needs to recover:addReplicaColl_shard1_replica3
[junit4] 2> 668885 INFO (updateExecutor-841-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 668885 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 668885 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 668885 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[addReplicaColl_shard1_replica3]
[junit4] 2> 668885 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 668885 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [addReplicaColl_shard1_replica3] as recovering, leader is [https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica1/] and I am [https://127.0.0.1:46068/solr/addReplicaColl_shard1_replica3/]
[junit4] 2> 668887 INFO (qtp15093928-4716) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica3&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=1029
[junit4] 2> 668889 INFO (recoveryExecutor-842-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:38755/solr]; [WaitForState: action=PREPRECOVERY&core=addReplicaColl_shard1_replica1&nodeName=127.0.0.1:46068_solr&coreNodeName=core_node5&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 668889 INFO (qtp16474945-4728) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:46068_solr&action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=1035
[junit4] 2> 668891 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node5, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 668891 INFO (qtp16474945-4731) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&property.instanceDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002 and sendToOCPQueue=true
[junit4] 2> 668891 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see addReplicaColl_shard1_replica1 (shard1 of addReplicaColl) have state: recovering
[junit4] 2> 668891 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=addReplicaColl, shard=shard1, thisCore=addReplicaColl_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:46068_solr, coreNodeName=core_node5, onlyIfActiveCheckResult=false, nodeProps: core_node5:{"core":"addReplicaColl_shard1_replica3","base_url":"https://127.0.0.1:46068/solr","node_name":"127.0.0.1:46068_solr","state":"down"}
[junit4] 2> 668892 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd addReplica() : {
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "property.instanceDir":"/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002",
[junit4] 2> "operation":"addreplica"}
[junit4] 2> 668892 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:38755_solr for creating new replica
[junit4] 2> 668892 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 668893 INFO (qtp16474945-4714) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica4&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&property.instanceDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002
[junit4] 2> 668995 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 668995 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 668995 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 668995 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 669891 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=addReplicaColl, shard=shard1, thisCore=addReplicaColl_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:46068_solr, coreNodeName=core_node5, onlyIfActiveCheckResult=false, nodeProps: core_node5:{"core":"addReplicaColl_shard1_replica3","base_url":"https://127.0.0.1:46068/solr","node_name":"127.0.0.1:46068_solr","state":"recovering"}
[junit4] 2> 669891 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 669891 INFO (qtp16474945-4727) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:46068_solr&onlyIfLeaderActive=true&core=addReplicaColl_shard1_replica1&coreNodeName=core_node5&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
[junit4] 2> 670162 INFO (qtp16474945-4714) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 670167 INFO (qtp16474945-4714) [ ] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica4] Schema name=minimal
[junit4] 2> 670169 INFO (qtp16474945-4714) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 670169 INFO (qtp16474945-4714) [ ] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica4' using configuration from collection addReplicaColl
[junit4] 2> 670170 INFO (qtp16474945-4714) [ ] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002/data/]
[junit4] 2> 670178 INFO (qtp16474945-4714) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 670178 INFO (qtp16474945-4714) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 670181 INFO (qtp16474945-4714) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 670181 INFO (qtp16474945-4714) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 670182 INFO (qtp16474945-4714) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a37534[addReplicaColl_shard1_replica4] main]
[junit4] 2> 670182 INFO (qtp16474945-4714) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 670182 INFO (qtp16474945-4714) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 670182 INFO (qtp16474945-4714) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 670183 INFO (searcherExecutor-2148-thread-1) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica4] Registered new searcher Searcher@a37534[addReplicaColl_shard1_replica4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 670183 INFO (qtp16474945-4714) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337573129289728
[junit4] 2> 670186 INFO (qtp16474945-4714) [ ] o.a.s.c.ZkController Core needs to recover:addReplicaColl_shard1_replica4
[junit4] 2> 670186 INFO (updateExecutor-836-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 670187 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 670187 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 670187 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[addReplicaColl_shard1_replica4]
[junit4] 2> 670187 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 670187 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [addReplicaColl_shard1_replica4] as recovering, leader is [https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica1/] and I am [https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica4/]
[junit4] 2> 670189 INFO (qtp16474945-4714) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica4&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&property.instanceDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002} status=0 QTime=1296
[junit4] 2> 670190 INFO (recoveryExecutor-837-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:38755/solr]; [WaitForState: action=PREPRECOVERY&core=addReplicaColl_shard1_replica1&nodeName=127.0.0.1:38755_solr&coreNodeName=core_node6&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 670190 INFO (qtp16474945-4731) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&property.instanceDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-002} status=0 QTime=1299
[junit4] 2> 670192 INFO (qtp16474945-4714) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node6, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 670193 INFO (qtp16474945-4714) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see addReplicaColl_shard1_replica1 (shard1 of addReplicaColl) have state: recovering
[junit4] 2> 670193 INFO (qtp16474945-4714) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=addReplicaColl, shard=shard1, thisCore=addReplicaColl_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:38755_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{"core":"addReplicaColl_shard1_replica4","base_url":"https://127.0.0.1:38755/solr","node_name":"127.0.0.1:38755_solr","state":"down"}
[junit4] 2> 670196 INFO (qtp16474945-4727) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=addReplicaColl_shard1_replica4&action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 670197 INFO (qtp16474945-4728) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params name=addReplicaColl_shard1_replica4&action=addreplica&collection=addReplicaColl&shard=shard1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 670198 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd addReplica() : {
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "name":"addReplicaColl_shard1_replica4",
[junit4] 2> "operation":"addreplica"}
[junit4] 2> 670198 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:44015_solr for creating new replica
[junit4] 2> 670198 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 670198 ERROR (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: addReplicaColl operation: addreplica failed:org.apache.solr.common.SolrException: Another replica with the same core name already exists for this collection
[junit4] 2> at org.apache.solr.cloud.AddReplicaCmd.addReplica(AddReplicaCmd.java:111)
[junit4] 2> at org.apache.solr.cloud.AddReplicaCmd.call(AddReplicaCmd.java:65)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@9-ea/ThreadPoolExecutor.java:1161)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@9-ea/ThreadPoolExecutor.java:635)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2>
[junit4] 2> 670201 INFO (qtp16474945-4728) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=addReplicaColl_shard1_replica4&action=addreplica&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=400 QTime=3
[junit4] 2> 670201 INFO (qtp16474945-4727) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params action=ADDREPLICA&collection=addReplicaColl&shard=shard1&property.name=propertyDotName&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 670203 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd addReplica() : {
[junit4] 2> "collection":"addReplicaColl",
[junit4] 2> "shard":"shard1",
[junit4] 2> "property.name":"propertyDotName",
[junit4] 2> "operation":"addreplica"}
[junit4] 2> 670203 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:44015_solr for creating new replica
[junit4] 2> 670203 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 670205 INFO (qtp31521719-4739) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&name=propertyDotName&action=CREATE&collection=addReplicaColl&shard=shard1&property.name=propertyDotName&wt=javabin&version=2
[junit4] 2> 670307 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 670307 INFO (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 670307 INFO (zkCallback-848-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 670307 INFO (zkCallback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 671193 INFO (qtp16474945-4714) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=addReplicaColl, shard=shard1, thisCore=addReplicaColl_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:38755_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{"core":"addReplicaColl_shard1_replica4","base_url":"https://127.0.0.1:38755/solr","node_name":"127.0.0.1:38755_solr","state":"recovering"}
[junit4] 2> 671193 INFO (qtp16474945-4714) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node6, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 671193 INFO (qtp16474945-4714) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:38755_solr&onlyIfLeaderActive=true&core=addReplicaColl_shard1_replica1&coreNodeName=core_node6&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
[junit4] 2> 671210 INFO (qtp31521719-4739) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 671218 INFO (qtp31521719-4739) [ ] o.a.s.s.IndexSchema [propertyDotName] Schema name=minimal
[junit4] 2> 671220 INFO (qtp31521719-4739) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 671221 INFO (qtp31521719-4739) [ ] o.a.s.c.CoreContainer Creating SolrCore 'propertyDotName' using configuration from collection addReplicaColl
[junit4] 2> 671221 INFO (qtp31521719-4739) [ ] o.a.s.c.SolrCore [[propertyDotName] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/propertyDotName], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF734053447575D6-001/tempDir-001/node2/./propertyDotName/data/]
[junit4] 2> 671229 INFO (qtp31521719-4739) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 671229 INFO (qtp31521719-4739) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 671234 INFO (qtp31521719-4739) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 671235 INFO (qtp31521719-4739) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 671235 INFO (qtp31521719-4739) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1eaebdb[propertyDotName] main]
[junit4] 2> 671236 INFO (qtp31521719-4739) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 671236 INFO (qtp31521719-4739) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 671237 INFO (qtp31521719-4739) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 671237 INFO (qtp31521719-4739) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1550337574234488832
[junit4] 2> 671239 INFO (searcherExecutor-2153-thread-1) [ ] o.a.s.c.SolrCore [propertyDotName] Registered new searcher Searcher@1eaebdb[propertyDotName] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 671241 INFO (qtp31521719-4739) [ ] o.a.s.c.ZkController Core needs to recover:propertyDotName
[junit4] 2> 671244 INFO (qtp31521719-4739) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&name=propertyDotName&action=CREATE&collection=addReplicaColl&shard=shard1&property.name=propertyDotName&wt=javabin&version=2} status=0 QTime=1040
[junit4] 2> 671245 INFO (updateExecutor-838-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 671249 INFO (qtp16474945-4727) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=ADDREPLICA&collection=addReplicaColl&shard=shard1&property.name=propertyDotName&wt=javabin&version=2} status=0 QTime=1047
[junit4] 2> 671249 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[EF734053447575D6]) [ ] o.a.s.SolrTestCaseJ4 ###Ending addReplicaTest
[junit4] 2> 671269 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 671270 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 671270 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[propertyDotName]
[junit4] 2> 671270 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 671270 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [propertyDotName] as recovering, leader is [https://127.0.0.1:38755/solr/addReplicaColl_shard1_replica1/] and I am [https://127.0.0.1:44015/solr/propertyDotName/]
[junit4] 2> 671287 INFO (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [https://127.0.0.1:38755/solr]; [WaitForState: action=PREPRECOVERY&core=addReplicaColl_shard1_replica1&nodeName=127.0.0.1:44015_solr&coreNodeName=core_node7&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 671305 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node7, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 671306 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see addReplicaColl_shard1_replica1 (shard1 of addReplicaColl) have state: recovering
[junit4] 2> 671306 INFO (qtp16474945-4727) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=addReplicaColl, shard=shard1, thisCore=addReplicaColl_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:44015_solr, coreNodeName=core_node7, onlyIfActiveCheckResult=false, nodeProps: core_node7:{"core":"propertyDotName","base_url":"https://127.0.0.1:44015/solr","node_name":"127.0.0.1:44015_solr","state":"down"}
[junit4] 2> 671334 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[EF734053447575D6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards
[junit4] 2> 671335 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[EF734053447575D6]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 671337 INFO (qtp16474945-4719) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=addReplicaColl&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 671338 INFO (OverseerThreadFactory-2104-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 671339 INFO (OverseerCollectionConfigSetProcessor-96896097677672459-127.0.0.1:38755_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000014 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 671344 INFO (qtp15093928-4743) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@18c3cda
[junit4] 2> 671344 INFO (qtp16474945-4714) [ ] o.a.s.c.SolrCore [addReplicaColl_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1d31926
[junit4] 2> 671346 WARN (qtp15093928-4724) [ ] o.a.s.c.RecoveryStrategy Stopping recovery for core=[addReplicaColl_shard1_replica3] coreNodeName=[core_node5]
[junit4] 2> 671346 WARN (qtp16474945-4854) [ ] o.a.s.c.RecoveryStrategy Stopping recovery for core=[addReplicaColl_shard1_replica4] coreNodeName=[core_node6]
[junit4] 2> 671346 INFO (qtp31521719-4740) [ ] o.a.s.c.SolrCore [addReplicaColl_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1edf467
[junit4] 2> 671346 INFO (qtp16474945-4854) [ ] o.a.s.c.SolrCore Core addReplicaColl_shard1_replica4 is not yet closed, waiting 100 ms before checking again.
[junit4] 2> 671347 INFO (qtp15093928-4724) [ ] o.a.s.c.SolrCore Core addReplicaColl_shard1_replica3 is not yet closed, waiting 100 ms before checking again.
[junit4] 2> 671347 INFO (qtp27562334-4735) [ ] o.a.s.c.SolrCore [addReplicaColl_shard2_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1780490
[junit4] 2> 671351 WARN (qtp31521719-4739) [ ] o.a.s.c.RecoveryStrategy Stopping recovery for core=[propertyDotName] coreNodeName=[core_node7]
[junit4] 2> 671352 INFO (qtp31521719-4739) [ ] o.a.s.c.SolrCore Core propertyDotName is not yet closed, waiting 100 ms before checking again.
[junit4] 2> 671353 ERROR (recoveryExecutor-839-thread-1) [ ] o.a.s.c.RecoveryStrategy Error while trying to recover. core=propertyDotName:java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:38755/solr
[junit4] 2> at java.util.concurrent.FutureTask.report(java.base@9-ea/FutureTask.java:122)
[junit4] 2> at java.util.concurrent.FutureTask.get(java.base@9-ea/FutureTask.java:191)
[junit4] 2> at org.apache.solr.cloud.RecoveryStrategy.sendPrepRecoveryCmd(RecoveryStrategy.java:6
[...truncated too long message...]
lback-843-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 765021 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44015_solr
[junit4] 2> 765021 INFO (zkCallback-847-thread-4) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 765021 INFO (zkCallback-847-thread-1) [ ] o.a.s.c.Overseer Overseer (id=96896097677672458-127.0.0.1:44015_solr-n_0000000003) starting
[junit4] 2> 765027 WARN (zkCallback-849-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 765028 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:45207) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1583e7cca33000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2> 765028 INFO (jetty-launcher-828-thread-8) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@664ad3{/solr,null,UNAVAILABLE}
[junit4] 2> 765127 WARN (OverseerStateUpdate-96896097677672458-127.0.0.1:44015_solr-n_0000000003) [ ] o.a.s.c.Overseer Solr cannot talk to ZK, exiting Overseer main queue loop
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:339)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:336)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:336)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.fetchZkChildren(DistributedQueue.java:299)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.firstChild(DistributedQueue.java:279)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.removeFirst(DistributedQueue.java:404)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:182)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:227)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2> 765128 INFO (OverseerStateUpdate-96896097677672458-127.0.0.1:44015_solr-n_0000000003) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44015_solr
[junit4] 2> 766518 WARN (zkCallback-882-thread-4) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 766518 INFO (jetty-launcher-828-thread-7) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@f70924{/solr,null,UNAVAILABLE}
[junit4] 2> 766519 INFO (jetty-launcher-828-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@132f81c{/solr,null,UNAVAILABLE}
[junit4] 2> 766528 WARN (zkCallback-847-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 766528 INFO (jetty-launcher-828-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@98bc33{/solr,null,UNAVAILABLE}
[junit4] 2> 766529 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45207 45207
[junit4] 2> 766534 INFO (Thread-1208) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45207 45207
[junit4] 2> 766534 WARN (Thread-1208) [ ] 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/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 158 /solr/clusterstate.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 173 /solr/collections
[junit4] 2> 33 /solr/overseer/collection-queue-work
[junit4] 2> 12 /solr/overseer/queue
[junit4] 2> 3 /solr/live_nodes
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 766535 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF734053447575D6]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Nov 07, 2016 11:13:41 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 767025 WARN (OverseerCollectionConfigSetProcessor-96896097677672458-127.0.0.1:44015_solr-n_0000000003) [ ] o.a.s.c.OverseerTaskProcessor Overseer cannot talk to ZK
[junit4] 2> Nov 07, 2016 11:14:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest:
[junit4] 2> 1) Thread[id=5086, name=OverseerHdfsCoreFailoverThread-96896097677672458-127.0.0.1:44015_solr-n_0000000003, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> at java.lang.Thread.sleep(java.base@9-ea/Native Method)
[junit4] 2> at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
[junit4] 2> at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] 2> Nov 07, 2016 11:14:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=5086, name=OverseerHdfsCoreFailoverThread-96896097677672458-127.0.0.1:44015_solr-n_0000000003, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] 2> Nov 07, 2016 11:14:01 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarity(queryNorm=true): {}, locale=en-MO, timezone=America/Regina
[junit4] 2> NOTE: Linux 4.4.0-42-generic i386/Oracle Corporation 9-ea (32-bit)/cpus=12,threads=1,free=94777632,total=280231936
[junit4] 2> NOTE: All tests run in this JVM: [TestRebalanceLeaders, SaslZkACLProviderTest, IndexSchemaTest, DistributedFacetPivotLongTailTest, TestNumericTerms64, RankQueryTest, TestRuleBasedAuthorizationPlugin, JavabinLoaderTest, TestFieldCollectionResource, DirectSolrConnectionTest, TestBlobHandler, TestSweetSpotSimilarityFactory, TestSchemaSimilarityResource, TestCustomSort, TestTolerantUpdateProcessorCloud, ShardRoutingCustomTest, OverseerModifyCollectionTest, PreAnalyzedUpdateProcessorTest, TestSolrQueryParserDefaultOperatorResource, TestSolrConfigHandler, TestQueryTypes, DOMUtilTest, DocValuesTest, TestSQLHandler, TestDistributedGrouping, TestCloudPseudoReturnFields, TestExpandComponent, TestReplicationHandlerBackup, SuggestComponentContextFilterQueryTest, TestJettySolrRunner, QueryParsingTest, AnalyticsQueryTest, TestPerFieldSimilarityWithDefaultOverride, TestFieldCacheWithThreads, ChaosMonkeySafeLeaderTest, IndexSchemaRuntimeFieldTest, SharedFSAutoReplicaFailoverUtilsTest, AlternateDirectoryTest, TestXIncludeConfig, TestManagedResource, ForceLeaderTest, SolrCmdDistributorTest, TestCorePropertiesReload, SpellCheckComponentTest, DistributedIntervalFacetingTest, DistributedSuggestComponentTest, TestHashPartitioner, PKIAuthenticationIntegrationTest, ShardRoutingTest, TestGraphTermsQParserPlugin, DirectoryFactoryTest, TestBulkSchemaAPI, AtomicUpdatesTest, SortByFunctionTest, TestWordDelimiterFilterFactory, HdfsCollectionsAPIDistributedZkTest, CoreMergeIndexesAdminHandlerTest, TestJsonFacetRefinement, BadComponentTest, TestNRTOpen, CollectionsAPIDistributedZkTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.seed=EF734053447575D6 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-MO -Dtests.timezone=America/Regina -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J1 | CollectionsAPIDistributedZkTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest:
[junit4] > 1) Thread[id=5086, name=OverseerHdfsCoreFailoverThread-96896097677672458-127.0.0.1:44015_solr-n_0000000003, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
[junit4] > at java.lang.Thread.sleep(java.base@9-ea/Native Method)
[junit4] > at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:137)
[junit4] > at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
[junit4] > at __randomizedtesting.SeedInfo.seed([EF734053447575D6]:0)
[junit4] Completed [241/647 (1!)] on J1 in 126.23s, 20 tests, 1 error <<< FAILURES!
[...truncated 52639 lines...]
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_102) - Build #
18225 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18225/
Java: 64bit/jdk1.8.0_102 -XX:+UseCompressedOops -XX:+UseSerialGC
All tests passed
Build Log:
[...truncated 24378 lines...]
-validate-source-patterns:
[source-patterns] tabs instead spaces: solr/example/files/conf/update-script.js
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 1 violations in source files (tabs instead spaces).
Total time: 61 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS-EA] Lucene-Solr-master-Linux (64bit/jdk-9-ea+140) - Build
# 18224 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18224/
Java: 64bit/jdk-9-ea+140 -XX:+UseCompressedOops -XX:+UseSerialGC
All tests passed
Build Log:
[...truncated 24389 lines...]
-validate-source-patterns:
[source-patterns] tabs instead spaces: solr/example/files/conf/update-script.js
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 1 violations in source files (tabs instead spaces).
Total time: 72 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk1.8.0_102) - Build #
18223 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18223/
Java: 64bit/jdk1.8.0_102 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
All tests passed
Build Log:
[...truncated 24377 lines...]
-validate-source-patterns:
[source-patterns] tabs instead spaces: solr/example/files/conf/update-script.js
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 1 violations in source files (tabs instead spaces).
Total time: 56 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any