Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.4/2/

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

Error Message:
Captured an uncaught exception in thread: Thread[id=20789, name=collection4, 
state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught 
exception in thread: Thread[id=20789, name=collection4, state=RUNNABLE, 
group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: java.lang.RuntimeException: 
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available 
to handle this request:[http://127.0.0.1:48400/_v/gl, 
http://127.0.0.1:32834/_v/gl, http://127.0.0.1:59552/_v/gl, 
http://127.0.0.1:42163/_v/gl, http://127.0.0.1:48458/_v/gl]
        at __randomizedtesting.SeedInfo.seed([43FFA8ED008CAE7]:0)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:886)
Caused by: org.apache.solr.client.solrj.SolrServerException: No live 
SolrServers available to handle this request:[http://127.0.0.1:48400/_v/gl, 
http://127.0.0.1:32834/_v/gl, http://127.0.0.1:59552/_v/gl, 
http://127.0.0.1:42163/_v/gl, http://127.0.0.1:48458/_v/gl]
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:352)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1099)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806)
        at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1573)
        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1594)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:876)
Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:48458/_v/gl: KeeperErrorCode = Session expired 
for /overseer/collection-queue-work/qnr-
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:574)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:240)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:229)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
        ... 7 more




Build Log:
[...truncated 11012 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/init-core-data-001
   [junit4]   2> 1727690 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[43FFA8ED008CAE7]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1727690 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[43FFA8ED008CAE7]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_v/gl
   [junit4]   2> 1727694 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1727694 INFO  (Thread-13200) [    ] o.a.s.c.ZkTestServer 
client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1727694 INFO  (Thread-13200) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1727794 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkTestServer start zk server on port:43088
   [junit4]   2> 1727794 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1727795 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1727798 INFO  (zkCallback-1368-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@28673ad5 
name:ZooKeeperConnection Watcher:127.0.0.1:43088 got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1727798 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1727798 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1727798 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /solr
   [junit4]   2> 1727800 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1727801 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1727802 INFO  (zkCallback-1369-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@533ce3a5 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1727802 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1727802 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1727802 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /collections/collection1
   [junit4]   2> 1727804 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
   [junit4]   2> 1727805 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
   [junit4]   2> 1727806 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
   [junit4]   2> 1727807 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
 to /configs/conf1/solrconfig.xml
   [junit4]   2> 1727807 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1727809 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/schema.xml
 to /configs/conf1/schema.xml
   [junit4]   2> 1727810 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
   [junit4]   2> 1727811 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
 to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1727811 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: 
/configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1727813 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
 to /configs/conf1/stopwords.txt
   [junit4]   2> 1727813 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1727814 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/protwords.txt
 to /configs/conf1/protwords.txt
   [junit4]   2> 1727814 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1727816 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/currency.xml
 to /configs/conf1/currency.xml
   [junit4]   2> 1727816 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
   [junit4]   2> 1727817 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
 to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1727817 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1727819 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
 to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1727819 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1727820 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
 to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1727820 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1727822 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
 to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1727822 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1727823 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
 to /configs/conf1/synonyms.txt
   [junit4]   2> 1727823 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1728078 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1
   [junit4]   2> 1728079 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.Server jetty-9.2.13.v20150730
   [junit4]   2> 1728081 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@264fdf40{/_v/gl,null,AVAILABLE}
   [junit4]   2> 1728083 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@4e4fc655{HTTP/1.1}{127.0.0.1:48400}
   [junit4]   2> 1728083 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.Server Started @1730718ms
   [junit4]   2> 1728083 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostPort=48400, 
hostContext=/_v/gl, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores,
 
solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/tempDir-001/control/data}
   [junit4]   2> 1728084 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): 
sun.misc.Launcher$AppClassLoader@7b3cb2c6
   [junit4]   2> 1728084 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001'
   [junit4]   2> 1728084 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1728084 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find 
system property or JNDI)
   [junit4]   2> 1728084 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1728085 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1728086 INFO  (zkCallback-1370-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@4a3a56bb 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1728086 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1728086 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1728087 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 1728087 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/solr.xml
   [junit4]   2> 1728099 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoresLocator Config-defined core root directory: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores
   [junit4]   2> 1728099 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer New CoreContainer 819249232
   [junit4]   2> 1728099 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer Loading cores into CoreContainer 
[instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001]
   [junit4]   2> 1728100 WARN  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/lib
 to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/lib
   [junit4]   2> 1728100 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme 
: ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 
10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 
5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 1728101 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1728101 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1728101 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.l.LogWatcher Registering Log Listener [Log4j 
(org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1728101 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43088/solr
   [junit4]   2> 1728101 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 1728102 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1728102 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1728103 INFO  (zkCallback-1372-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@4a402cac 
name:ZooKeeperConnection Watcher:127.0.0.1:43088 got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1728104 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1728104 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1728105 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ConnectionManager Waiting for client 
to connect to ZooKeeper
   [junit4]   2> 1728106 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@7dffbaef 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1728106 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ConnectionManager Client is connected 
to ZooKeeper
   [junit4]   2> 1728107 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
   [junit4]   2> 1728110 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer/collection-queue-work
   [junit4]   2> 1728113 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer/collection-map-running
   [junit4]   2> 1728114 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer/collection-map-completed
   [junit4]   2> 1728116 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer/collection-map-failure
   [junit4]   2> 1728118 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
   [junit4]   2> 1728119 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
   [junit4]   2> 1728120 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/clusterstate.json
   [junit4]   2> 1728121 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: /security.json
   [junit4]   2> 1728122 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:48400__v%2Fgl
   [junit4]   2> 1728122 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/live_nodes/127.0.0.1:48400__v%2Fgl
   [junit4]   2> 1728124 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
   [junit4]   2> 1728125 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer_elect/election
   [junit4]   2> 1728126 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1728126 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.LeaderElector Joined leadership 
election with path: 
/overseer_elect/election/94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000
   [junit4]   2> 1728127 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.OverseerElectionContext I am going to 
be the leader 127.0.0.1:48400__v%2Fgl
   [junit4]   2> 1728127 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer_elect/leader
   [junit4]   2> 1728128 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer Overseer 
(id=94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) starting
   [junit4]   2> 1728129 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/overseer/queue-work
   [junit4]   2> 1728134 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.OverseerAutoReplicaFailoverThread 
Starting OverseerAutoReplicaFailoverThread 
autoReplicaFailoverWorkLoopDelay=10000 
autoReplicaFailoverWaitAfterExpiration=10000 
autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 1728135 INFO  
(OverseerCollectionConfigSetProcessor-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000)
 [n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.OverseerTaskProcessor Process current 
queue of overseer operations
   [junit4]   2> 1728135 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader Updating cluster state 
from ZooKeeper... 
   [junit4]   2> 1728135 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer Starting to work on the main 
queue
   [junit4]   2> 1728163 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.CoreContainer Security conf doesn't 
exist. Skipping setup for authorization module.
   [junit4]   2> 1728163 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.CoreContainer No authentication plugin 
used.
   [junit4]   2> 1728164 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.CoresLocator Looking for core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores
   [junit4]   2> 1728165 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.SolrCore Created CoreDescriptor: 
{absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/,
 
instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1,
 shard=, config=solrconfig.xml, coreNodeName=, collection=control_collection, 
transient=false, configSetProperties=configsetprops.json, dataDir=data/, 
name=collection1, loadOnStartup=true, schema=schema.xml}
   [junit4]   2> 1728165 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.CoresLocator Found core collection1 in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/
   [junit4]   2> 1728165 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.CoresLocator Found 1 core definitions
   [junit4]   2> 1728166 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.s.SolrDispatchFilter 
user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
   [junit4]   2> 1728166 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.s.SolrDispatchFilter 
SolrDispatchFilter.init() done
   [junit4]   2> 1728166 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController publishing state=down
   [junit4]   2> 1728167 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController numShards not found on descriptor - reading it from system 
property
   [junit4]   2> 1728168 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:48400/_v/gl";,
   [junit4]   2>   "shard":null,
   [junit4]   2>   "node_name":"127.0.0.1:48400__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"1"} current state version: 0
   [junit4]   2> 1728168 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController look for our core node name
   [junit4]   2> 1728168 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ReplicaMutator Update state 
numShards=1 message={
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:48400/_v/gl";,
   [junit4]   2>   "shard":null,
   [junit4]   2>   "node_name":"127.0.0.1:48400__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"1"}
   [junit4]   2> 1728169 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ClusterStateMutator building a new 
cName: control_collection
   [junit4]   2> 1728169 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 1728170 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader A cluster state change: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, 
has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1729169 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1729169 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController Check for collection zkNode:control_collection
   [junit4]   2> 1729169 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ZkController Collection zkNode exists
   [junit4]   2> 1729169 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.c.ZkStateReader Load collection config 
from:/collections/control_collection
   [junit4]   2> 1729170 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 
specified config exists in ZooKeeper
   [junit4]   2> 1729170 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1'
   [junit4]   2> 1729170 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1729170 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find 
system property or JNDI)
   [junit4]   2> 1729172 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] o.a.s.c.Config 
loaded config solrconfig.xml with version 0 
   [junit4]   2> 1729178 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 1729190 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.4.0
   [junit4]   2> 1729229 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] o.a.s.c.Config 
Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1729236 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1729486 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1729493 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 1729494 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 1729502 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1729505 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1729507 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 1729508 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1729508 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1729508 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 1729509 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1729509 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1729510 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default 
properties: Can't find resource 'configsetprops.json' in classpath or 
'/configs/conf1', 
cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
   [junit4]   2> 1729510 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection   x:collection1] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection control_collection
   [junit4]   2> 1729510 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1729510 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1],
 dataDir=[null]
   [junit4]   2> 1729510 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr 
mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dce7d2b
   [junit4]   2> 1729511 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data
   [junit4]   2> 1729511 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore New index directory detected: old=null 
new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data/index/
   [junit4]   2> 1729511 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 
'/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data/index'
 doesn't exist. Creating new index...
   [junit4]   2> 1729512 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data/index
   [junit4]   2> 1729512 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=27, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=6.037109375, 
floorSegmentMB=2.1728515625, forceMergeDeletesPctAllowed=25.494101089767646, 
segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1729514 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>        
commit{dir=RawDirectoryWrapper(SimpleFSDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/index-SimpleFSDirectory-001
 
lockFactory=org.apache.lucene.store.NativeFSLockFactory@5df614ad),segFN=segments_1,generation=1}
   [junit4]   2> 1729514 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 1729514 INFO  
(OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:48400__v%2Fgl 
c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore 
Looking for old index directories to cleanup for core collection1 in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data/
   [junit4]   2> 1729515 WARN  
(OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:48400__v%2Fgl 
c:control_collection s:shard1 r:core_node1 x:collection1] 
o.a.s.c.DirectoryFactory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/control-001/cores/collection1/data/
 does not point to a valid data directory; skipping clean-up of old index 
directories.
   [junit4]   2> 1729517 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1729517 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 1729518 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as 
default, creating implicit default
   [junit4]   2> 1729518 WARN  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler 
{type = requestHandler,name = /dump,class = DumpRequestHandler,args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 1729521 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1729522 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1729523 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1729524 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 1729527 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.RequestHandlers Registered paths: 
/get,/config,/admin/mbeans,/schema,/dump,/admin/system,/admin/luke,/replication,/admin/segments,/admin/threads,standard,/admin/properties,/update/csv,/update/json,/admin/ping,/admin/logging,/update/json/docs,/admin/plugins,/admin/file,/update
   [junit4]   2> 1729528 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore Using default statsCache cache: 
org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1729528 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1729528 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= 
defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 
numVersionBuckets=65536
   [junit4]   2> 1729529 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
   [junit4]   2> 1729529 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
   [junit4]   2> 1729529 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.MockRandomMergePolicy: 
org.apache.lucene.index.MockRandomMergePolicy@624638ec
   [junit4]   2> 1729530 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>        
commit{dir=RawDirectoryWrapper(SimpleFSDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/index-SimpleFSDirectory-001
 
lockFactory=org.apache.lucene.store.NativeFSLockFactory@5df614ad),segFN=segments_1,generation=1}
   [junit4]   2> 1729530 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 1729530 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@4f364ff1[collection1] 
main
   [junit4]   2> 1729530 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.c.ZkStateReader Load collection config 
from:/collections/control_collection
   [junit4]   2> 1729531 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection 
configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1729532 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based 
storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO 
with znodeBase: /configs/conf1
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode 
/configs/conf1/_rest_managed.json
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path 
_rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 1729533 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1729534 INFO  
(searcherExecutor-5504-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@4f364ff1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1729534 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed 
version buckets
   [junit4]   2> 1729534 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 
65536 version buckets from index
   [junit4]   2> 1729534 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed 
version bucket highest value from index
   [junit4]   2> 1729534 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1519001534600314880
   [junit4]   2> 1729536 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with 
highest version 1519001534600314880
   [junit4]   2> 1729536 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
   [junit4]   2> 1729537 INFO  
(coreLoadExecutor-5503-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 1729537 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController Register replica - core:collection1 
address:http://127.0.0.1:48400/_v/gl collection:control_collection shard:shard1
   [junit4]   2> 1729538 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.c.SolrZkClient makePath: 
/collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1729540 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: 
/collections/control_collection/leader_elect/shard1/election/94937595791998980-core_node1-n_0000000000
   [junit4]   2> 1729541 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process 
for shard shard1
   [junit4]   2> 1729542 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to 
continue.
   [junit4]   2> 1729542 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try 
and sync
   [junit4]   2> 1729542 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:48400/_v/gl/collection1/
   [junit4]   2> 1729542 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1729542 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:48400/_v/gl/collection1/ 
has no replicas
   [junit4]   2> 1729543 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection"} current state version: 1
   [junit4]   2> 1729543 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.c.SolrZkClient makePath: 
/collections/control_collection/leaders/shard1
   [junit4]   2> 1729545 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContextBase Creating leader 
registration node
   [junit4]   2> 1729547 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:48400/_v/gl/collection1/ shard1
   [junit4]   2> 1729547 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "base_url":"http://127.0.0.1:48400/_v/gl";,
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active"} current state version: 1
   [junit4]   2> 1729650 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader A cluster state change: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, 
has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1729668 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1729669 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1729670 INFO  (zkCallback-1375-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@48e3c193 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1729670 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1729670 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1729670 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 1729672 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection 
loss:false
   [junit4]   2> 1729698 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController We are 
http://127.0.0.1:48400/_v/gl/collection1/ and leader is 
http://127.0.0.1:48400/_v/gl/collection1/
   [junit4]   2> 1729698 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 
baseURL=http://127.0.0.1:48400/_v/gl
   [junit4]   2> 1729698 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1729698 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController publishing state=active
   [junit4]   2> 1729698 INFO  
(coreZkRegister-5497-thread-1-processing-c:control_collection 
n:127.0.0.1:48400__v%2Fgl s:shard1 x:collection1 r:core_node1) 
[n:127.0.0.1:48400__v%2Fgl c:control_collection s:shard1 r:core_node1 
x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading 
it from system property
   [junit4]   2> 1729700 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:48400/_v/gl";,
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "node_name":"127.0.0.1:48400__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"2"} current state version: 2
   [junit4]   2> 1729700 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ReplicaMutator Update state 
numShards=2 message={
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:48400/_v/gl";,
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "node_name":"127.0.0.1:48400__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"2"}
   [junit4]   2> 1729802 INFO  (zkCallback-1375-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent 
state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred 
- updating... (live nodes size: 1)
   [junit4]   2> 1729802 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader A cluster state change: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, 
has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1729929 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1
   [junit4]   2> 1729930 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001
   [junit4]   2> 1729931 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.Server jetty-9.2.13.v20150730
   [junit4]   2> 1729932 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7553442c{/_v/gl,null,AVAILABLE}
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@1d0beb2e{HTTP/1.1}{127.0.0.1:32834}
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.e.j.s.Server Started @1732568ms
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores,
 solrconfig=solrconfig.xml, 
solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/tempDir-001/jetty1,
 hostContext=/_v/gl, hostPort=32834}
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): 
sun.misc.Launcher$AppClassLoader@7b3cb2c6
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001'
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1729933 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find 
system property or JNDI)
   [junit4]   2> 1729934 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1729934 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1729935 INFO  (zkCallback-1376-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@471f0be9 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1729935 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1729936 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1729936 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 1729936 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/solr.xml
   [junit4]   2> 1729949 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoresLocator Config-defined core root directory: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores
   [junit4]   2> 1729949 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer New CoreContainer 1608948250
   [junit4]   2> 1729949 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer Loading cores into CoreContainer 
[instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001]
   [junit4]   2> 1729949 WARN  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.CoreContainer Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/lib
 to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/lib
   [junit4]   2> 1729949 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme 
: ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 
10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 
5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 1729950 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.l.LogWatcher Registering Log Listener [Log4j 
(org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43088/solr
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 1729951 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 1729952 INFO  (zkCallback-1378-thread-1) [    ] 
o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@baec89d name:ZooKeeperConnection 
Watcher:127.0.0.1:43088 got event WatchedEvent state:SyncConnected type:None 
path:null path:null type:None
   [junit4]   2> 1729953 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 1729954 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) [    ] 
o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 1729955 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ConnectionManager Waiting for client 
to connect to ZooKeeper
   [junit4]   2> 1729956 INFO  
(zkCallback-1379-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ConnectionManager Watcher 
org.apache.solr.common.cloud.ConnectionManager@6c8ecf69 
name:ZooKeeperConnection Watcher:127.0.0.1:43088/solr got event WatchedEvent 
state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1729956 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ConnectionManager Client is connected 
to ZooKeeper
   [junit4]   2> 1729961 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ZkStateReader Updating cluster state 
from ZooKeeper... 
   [junit4]   2> 1730965 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:32834__v%2Fgl
   [junit4]   2> 1730966 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.SolrZkClient makePath: 
/live_nodes/127.0.0.1:32834__v%2Fgl
   [junit4]   2> 1730967 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader A live node change: 
WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has 
occurred - updating... (live nodes size: 1)
   [junit4]   2> 1730967 INFO  (zkCallback-1375-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected 
type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live 
nodes size: 1)
   [junit4]   2> 1730967 INFO  
(zkCallback-1379-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ZkStateReader A live node change: 
WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has 
occurred - updating... (live nodes size: 1)
   [junit4]   2> 1730969 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1730969 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.LeaderElector Joined leadership 
election with path: 
/overseer_elect/election/94937595791998984-127.0.0.1:32834__v%2Fgl-n_0000000001
   [junit4]   2> 1730970 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.LeaderElector Watching path 
/overseer_elect/election/94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000 
to know if I could be the leader
   [junit4]   2> 1730982 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.CoreContainer Security conf doesn't 
exist. Skipping setup for authorization module.
   [junit4]   2> 1730982 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.CoreContainer No authentication plugin 
used.
   [junit4]   2> 1730983 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.CoresLocator Looking for core 
definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores
   [junit4]   2> 1730984 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.SolrCore Created CoreDescriptor: 
{absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1/,
 schema=schema.xml, collection=collection1, transient=false, coreNodeName=, 
loadOnStartup=true, name=collection1, 
instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1,
 configSetProperties=configsetprops.json, config=solrconfig.xml, dataDir=data/, 
shard=}
   [junit4]   2> 1730984 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.CoresLocator Found core collection1 in 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1/
   [junit4]   2> 1730984 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.CoresLocator Found 1 core definitions
   [junit4]   2> 1730985 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.s.SolrDispatchFilter 
user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
   [junit4]   2> 1730985 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
publishing state=down
   [junit4]   2> 1730985 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[43FFA8ED008CAE7]) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.s.SolrDispatchFilter 
SolrDispatchFilter.init() done
   [junit4]   2> 1730985 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
numShards not found on descriptor - reading it from system property
   [junit4]   2> 1730986 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.Overseer processMessage: queueSize: 1, 
message = {
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:32834/_v/gl";,
   [junit4]   2>   "shard":null,
   [junit4]   2>   "node_name":"127.0.0.1:32834__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"2"} current state version: 3
   [junit4]   2> 1730987 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
look for our core node name
   [junit4]   2> 1730987 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ReplicaMutator Update state 
numShards=2 message={
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:32834/_v/gl";,
   [junit4]   2>   "shard":null,
   [junit4]   2>   "node_name":"127.0.0.1:32834__v%2Fgl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "operation":"state",
   [junit4]   2>   "numShards":"2"}
   [junit4]   2> 1730987 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ClusterStateMutator building a new 
cName: collection1
   [junit4]   2> 1730987 INFO  
(OverseerStateUpdate-94937595791998980-127.0.0.1:48400__v%2Fgl-n_0000000000) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard2
   [junit4]   2> 1731089 INFO  
(zkCallback-1373-thread-1-processing-n:127.0.0.1:48400__v%2Fgl) 
[n:127.0.0.1:48400__v%2Fgl    ] o.a.s.c.c.ZkStateReader A cluster state change: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, 
has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1731089 INFO  
(zkCallback-1379-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl    ] o.a.s.c.c.ZkStateReader A cluster state change: 
WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, 
has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1731089 INFO  (zkCallback-1375-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent 
state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred 
- updating... (live nodes size: 2)
   [junit4]   2> 1731987 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1731987 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
Check for collection zkNode:collection1
   [junit4]   2> 1731988 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.ZkController 
Collection zkNode exists
   [junit4]   2> 1731988 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.c.ZkStateReader Load collection config from:/collections/collection1
   [junit4]   2> 1731989 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.c.ZkStateReader path=/collections/collection1 configName=conf1 
specified config exists in ZooKeeper
   [junit4]   2> 1731989 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1'
   [junit4]   2> 1731989 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1731989 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find 
system property or JNDI)
   [junit4]   2> 1731991 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.Config loaded 
config solrconfig.xml with version 0 
   [junit4]   2> 1731997 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.SolrConfig 
current version of requestparams : -1
   [junit4]   2> 1732008 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 5.4.0
   [junit4]   2> 1732034 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.Config Loaded 
SolrConfig: solrconfig.xml
   [junit4]   2> 1732040 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 1732283 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1732290 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.s.IndexSchema 
default search field in schema is text
   [junit4]   2> 1732292 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.s.IndexSchema 
unique key field: id
   [junit4]   2> 1732300 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1732303 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 1732305 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 1732306 WARN  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1732306 WARN  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1732306 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 1732307 WARN  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 1732307 WARN  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 1732307 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] 
o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default 
properties: Can't find resource 'configsetprops.json' in classpath or 
'/configs/conf1', 
cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2
   [junit4]   2> 1732307 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1732308 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1732308 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl c:collection1 s:shard2 r:core_node1 x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_43FFA8ED008CAE7-001/shard-1-001/cores/collection1],
 dataDir=[null]
   [junit4]   2> 1732308 INFO  
(coreLoadExecutor-5514-thread-1-processing-n:127.0.0.1:32834__v%2Fgl) 
[n:127.0.0.1:32834__v%2Fgl 

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

ava.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: No 
live SolrServers available to handle this 
request:[http://127.0.0.1:48400/_v/gl, http://127.0.0.1:32834/_v/gl, 
http://127.0.0.1:59552/_v/gl, http://127.0.0.1:42163/_v/gl, 
http://127.0.0.1:48458/_v/gl]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([43FFA8ED008CAE7]:0)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:886)
   [junit4]    > Caused by: org.apache.solr.client.solrj.SolrServerException: 
No live SolrServers available to handle this 
request:[http://127.0.0.1:48400/_v/gl, http://127.0.0.1:32834/_v/gl, 
http://127.0.0.1:59552/_v/gl, http://127.0.0.1:42163/_v/gl, 
http://127.0.0.1:48458/_v/gl]
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:352)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1099)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806)
   [junit4]    >        at 
org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1573)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1594)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:876)
   [junit4]    > Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:48458/_v/gl: KeeperErrorCode = Session expired 
for /overseer/collection-queue-work/qnr-
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:574)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:240)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:229)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
   [junit4]    >        ... 7 moreThrowable #6: 
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught 
exception in thread: Thread[id=20785, name=collection0, state=RUNNABLE, 
group=TGRP-CollectionsAPIDistributedZkTest]
   [junit4]    > Caused by: java.lang.RuntimeException: 
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available 
to handle this request:[http://127.0.0.1:48400/_v/gl, 
http://127.0.0.1:32834/_v/gl, http://127.0.0.1:59552/_v/gl, 
http://127.0.0.1:42163/_v/gl, http://127.0.0.1:48458/_v/gl]
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([43FFA8ED008CAE7]:0)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:886)
   [junit4]    > Caused by: org.apache.solr.client.solrj.SolrServerException: 
No live SolrServers available to handle this 
request:[http://127.0.0.1:48400/_v/gl, http://127.0.0.1:32834/_v/gl, 
http://127.0.0.1:59552/_v/gl, http://127.0.0.1:42163/_v/gl, 
http://127.0.0.1:48458/_v/gl]
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:352)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1099)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:870)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:806)
   [junit4]    >        at 
org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1573)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1594)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:876)
   [junit4]    > Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:48458/_v/gl: KeeperErrorCode = Session expired 
for /overseer/collection-queue-work/qnr-
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:574)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:240)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:229)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
   [junit4]    >        ... 7 more
   [junit4]   2> 2166311 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[43FFA8ED008CAE7]-worker) 
[n:127.0.0.1:59552__v%2Fgl c:addReplicaColl s:shard2 r:core_node2 
x:addReplicaColl_shard2_replica2] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: test params are: codec=CheapBastard, 
sim=DefaultSimilarity, locale=ar_SD, timezone=America/Montevideo
   [junit4]   2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 
1.7.0_80 (64-bit)/cpus=4,threads=1,free=170122736,total=473956352
   [junit4]   2> NOTE: All tests run in this JVM: 
[TestSweetSpotSimilarityFactory, TestUtils, TestMissingGroups, 
StatsComponentTest, DirectSolrConnectionTest, HdfsSyncSliceTest, 
FullSolrCloudDistribCmdsTest, HighlighterConfigTest, 
CoreAdminCreateDiscoverTest, SparseHLLTest, BadComponentTest, 
TestPHPSerializedResponseWriter, TestStressReorder, TestFileDictionaryLookup, 
QueryParsingTest, LeaderElectionTest, TestSchemaVersionResource, 
TestDistribDocBasedVersion, RemoteQueryErrorTest, RuleEngineTest, TestSort, 
DistribCursorPagingTest, TestZkChroot, TestLeaderElectionZkExpiry, 
TestExactSharedStatsCache, TestSolrIndexConfig, DistributedFacetPivotLargeTest, 
InfoHandlerTest, TestComplexPhraseQParserPlugin, TestCloudPivotFacet, 
TestMiniSolrCloudCluster, DateRangeFieldTest, TestPerFieldSimilarity, 
TestTrackingShardHandlerFactory, AddSchemaFieldsUpdateProcessorFactoryTest, 
SolrXmlInZkTest, ScriptEngineTest, TestScoreJoinQPScore, ForceLeaderTest, 
DistanceUnitsTest, QueryResultKeyTest, TestPostingsSolrHighlighter, 
TestChildDocTransformer, TermVectorComponentDistributedTest, 
DocExpirationUpdateProcessorFactoryTest, TestElisionMultitermQuery, 
TestIndexSearcher, ResponseHeaderTest, TestRecovery, 
HdfsChaosMonkeySafeLeaderTest, TestSuggestSpellingConverter, 
DistributedQueryComponentOptimizationTest, TestConfigOverlay, 
ConcurrentDeleteAndCreateCollectionTest, HdfsThreadLeakTest, 
BasicDistributedZk2Test, TestIntervalFaceting, TestManagedResourceStorage, 
TestCSVResponseWriter, OverseerStatusTest, CurrencyFieldXmlFileTest, 
HdfsCollectionsAPIDistributedZkTest, HLLSerializationTest, 
TriLevelCompositeIdRoutingTest, BadIndexSchemaTest, TestJmxIntegration, 
TestSearchPerf, TestHashQParserPlugin, TestCoreDiscovery, TestCharFilters, 
SimpleFacetsTest, TestGroupingSearch, SliceStateTest, 
BinaryUpdateRequestHandlerTest, TestStressRecovery, RegexBoostProcessorTest, 
TestSolrDeletionPolicy1, FieldMutatingUpdateProcessorTest, 
AliasIntegrationTest, XmlUpdateRequestHandlerTest, TestReloadDeadlock, 
TestLRUStatsCache, DistributedFacetPivotSmallTest, DirectUpdateHandlerTest, 
DocValuesMultiTest, TestFieldTypeCollectionResource, 
TestBlendedInfixSuggestions, TestSolrQueryParserResource, 
ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed [284/551] on J2 in 439.28s, 1 test, 1 error <<< FAILURES!

[...truncated 837 lines...]
   [junit4] JVM J2: stdout was not empty, see: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build/solr-core/test/temp/junit4-J2-20151127_133017_863.sysout
   [junit4] >>> JVM J2: stdout (verbatim) ----
   [junit4] java.lang.OutOfMemoryError: GC overhead limit exceeded
   [junit4] Dumping heap to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/heapdumps/java_pid6270.hprof
 ...
   [junit4] Heap dump file created [611747365 bytes in 4.907 secs]
   [junit4] <<< JVM J2: EOF ----

[...truncated 16 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:792: 
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:729: 
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/build.xml:59: 
The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/build.xml:233:
 The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/solr/common-build.xml:526:
 The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1452:
 The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.4/lucene/common-build.xml:1006:
 There were test failures: 551 suites (7 ignored), 2177 tests, 1 error, 32 
ignored (18 assumptions) [seed: 43FFA8ED008CAE7]

Total time: 189 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to